diff --git a/integrationTests/diagnostics-bun/package.json b/integrationTests/diagnostics-bun/package.json new file mode 100644 index 0000000000..4f837f7ab9 --- /dev/null +++ b/integrationTests/diagnostics-bun/package.json @@ -0,0 +1,10 @@ +{ + "description": "graphql-js tracing channels should publish on node:diagnostics_channel (Bun)", + "private": true, + "scripts": { + "test": "docker run --rm --volume \"$PWD\":/usr/src/app -w /usr/src/app oven/bun:\"$BUN_VERSION\"-slim bun test.js" + }, + "dependencies": { + "graphql": "file:../graphql.tgz" + } +} diff --git a/integrationTests/diagnostics-bun/test.js b/integrationTests/diagnostics-bun/test.js new file mode 100644 index 0000000000..bcd0bbdb4f --- /dev/null +++ b/integrationTests/diagnostics-bun/test.js @@ -0,0 +1,342 @@ +// TracingChannel is marked experimental in Node's docs but is shipped on +// every runtime graphql-js supports. This test exercises it directly. +/* eslint-disable n/no-unsupported-features/node-builtins */ + +import assert from 'node:assert/strict'; +import { AsyncLocalStorage } from 'node:async_hooks'; +import dc from 'node:diagnostics_channel'; + +import { buildSchema, execute, parse, subscribe, validate } from 'graphql'; + +function runParseCases() { + // graphql:parse - synchronous. + { + const events = []; + const handler = { + start: (msg) => events.push({ kind: 'start', source: msg.source }), + end: (msg) => events.push({ kind: 'end', source: msg.source }), + asyncStart: (msg) => + events.push({ kind: 'asyncStart', source: msg.source }), + asyncEnd: (msg) => events.push({ kind: 'asyncEnd', source: msg.source }), + error: (msg) => + events.push({ kind: 'error', source: msg.source, error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:parse'); + channel.subscribe(handler); + + try { + const doc = parse('{ field }'); + assert.equal(doc.kind, 'Document'); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].source, '{ field }'); + assert.equal(events[1].source, '{ field }'); + } finally { + channel.unsubscribe(handler); + } + } + + // graphql:parse - error path fires start, error, end. + { + const events = []; + const handler = { + start: (msg) => events.push({ kind: 'start', source: msg.source }), + end: (msg) => events.push({ kind: 'end', source: msg.source }), + error: (msg) => + events.push({ kind: 'error', source: msg.source, error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:parse'); + channel.subscribe(handler); + + try { + assert.throws(() => parse('{ ')); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'error', 'end'], + ); + assert.ok(events[1].error instanceof Error); + } finally { + channel.unsubscribe(handler); + } + } +} + +function runValidateCase() { + const schema = buildSchema(`type Query { field: String }`); + const doc = parse('{ field }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + document: msg.document, + }), + end: () => events.push({ kind: 'end' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:validate'); + channel.subscribe(handler); + + try { + const errors = validate(schema, doc); + assert.deepEqual(errors, []); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].schema, schema); + assert.equal(events[0].document, doc); + } finally { + channel.unsubscribe(handler); + } +} + +function runExecuteCase() { + const schema = buildSchema(`type Query { hello: String }`); + const document = parse('query Greeting { hello }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + document: msg.document, + variableValues: msg.variableValues, + operationName: msg.operationName, + operationType: msg.operationType, + }), + end: () => events.push({ kind: 'end' }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:execute'); + channel.subscribe(handler); + + try { + const result = execute({ + schema, + document, + rootValue: { hello: 'world' }, + }); + assert.equal(result.data.hello, 'world'); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].operationType, 'query'); + assert.equal(events[0].operationName, 'Greeting'); + assert.equal(events[0].document, document); + assert.equal(events[0].schema, schema); + } finally { + channel.unsubscribe(handler); + } +} + +function runExecuteRootSelectionSetCase() { + const schema = buildSchema(`type Query { hello: String }`); + const document = parse('query Greeting { hello }'); + const operation = document.definitions[0]; + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + operation: msg.operation, + variableValues: msg.variableValues, + operationName: msg.operationName, + operationType: msg.operationType, + }), + end: (msg) => events.push({ kind: 'end', result: msg.result }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:execute:rootSelectionSet'); + channel.subscribe(handler); + + try { + const result = execute({ + schema, + document, + rootValue: { hello: 'world' }, + }); + assert.equal(result.data.hello, 'world'); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].operationType, 'query'); + assert.equal(events[0].operationName, 'Greeting'); + assert.equal(events[0].operation, operation); + assert.equal(events[0].schema, schema); + assert.equal(events[1].result, result); + } finally { + channel.unsubscribe(handler); + } +} + +async function runSubscribeCase() { + async function* ticks() { + yield { tick: 'one' }; + } + + const schema = buildSchema(` + type Query { dummy: String } + type Subscription { tick: String } + `); + // buildSchema doesn't attach a subscribe resolver to fields; inject one. + schema.getSubscriptionType().getFields().tick.subscribe = () => ticks(); + + const document = parse('subscription Tick { tick }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + document: msg.document, + variableValues: msg.variableValues, + operationName: msg.operationName, + operationType: msg.operationType, + }), + end: () => events.push({ kind: 'end' }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:subscribe'); + channel.subscribe(handler); + + try { + const result = subscribe({ schema, document }); + const stream = typeof result.then === 'function' ? await result : result; + if (stream[Symbol.asyncIterator]) { + await stream.return?.(); + } + // Subscription setup is synchronous here; start/end fire, no async tail. + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].operationType, 'subscription'); + assert.equal(events[0].operationName, 'Tick'); + } finally { + channel.unsubscribe(handler); + } +} + +function runResolveCase() { + const schema = buildSchema( + `type Query { hello: String nested: Nested } type Nested { leaf: String }`, + ); + const document = parse('{ hello nested { leaf } }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + fieldName: msg.fieldName, + parentType: msg.parentType, + fieldType: msg.fieldType, + args: msg.args, + isDefaultResolver: msg.isDefaultResolver, + fieldPath: msg.fieldPath, + }), + end: () => events.push({ kind: 'end' }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:resolve'); + channel.subscribe(handler); + + try { + const rootValue = { hello: () => 'world', nested: { leaf: 'leaf-value' } }; + execute({ schema, document, rootValue }); + + const starts = events.filter((e) => e.kind === 'start'); + const paths = starts.map((e) => e.fieldPath); + assert.deepEqual(paths, ['hello', 'nested', 'nested.leaf']); + + const hello = starts.find((e) => e.fieldName === 'hello'); + assert.equal(hello.parentType, 'Query'); + assert.equal(hello.fieldType, 'String'); + // buildSchema never attaches field.resolve; all fields report as trivial. + assert.equal(hello.isDefaultResolver, true); + } finally { + channel.unsubscribe(handler); + } +} + +function runNoSubscriberCase() { + const doc = parse('{ field }'); + assert.equal(doc.kind, 'Document'); +} + +async function runAlsPropagationCase() { + // A subscriber that binds a store on the `start` sub-channel should be able + // to read it in every lifecycle handler (start, end, asyncStart, asyncEnd). + // This is what APMs use to parent child spans to the current operation + // without threading state through the context object. + const als = new AsyncLocalStorage(); + const channel = dc.tracingChannel('graphql:execute'); + channel.start.bindStore(als, (context) => ({ + operationName: context.operationName, + })); + + const seen = {}; + const handler = { + start: () => (seen.start = als.getStore()), + end: () => (seen.end = als.getStore()), + asyncStart: () => (seen.asyncStart = als.getStore()), + asyncEnd: () => (seen.asyncEnd = als.getStore()), + }; + channel.subscribe(handler); + + try { + const schema = buildSchema(`type Query { slow: String }`); + const document = parse('query Slow { slow }'); + const rootValue = { slow: () => Promise.resolve('done') }; + + await execute({ schema, document, rootValue }); + + assert.deepEqual(seen.start, { operationName: 'Slow' }); + assert.deepEqual(seen.end, { operationName: 'Slow' }); + assert.deepEqual(seen.asyncStart, { operationName: 'Slow' }); + assert.deepEqual(seen.asyncEnd, { operationName: 'Slow' }); + } finally { + channel.unsubscribe(handler); + channel.start.unbindStore(als); + } +} + +async function main() { + runParseCases(); + runValidateCase(); + runExecuteCase(); + runExecuteRootSelectionSetCase(); + await runSubscribeCase(); + runResolveCase(); + await runAlsPropagationCase(); + runNoSubscriberCase(); + console.log('diagnostics integration test passed'); +} + +main(); diff --git a/integrationTests/diagnostics-deno-with-deno-build/deno.json b/integrationTests/diagnostics-deno-with-deno-build/deno.json new file mode 100644 index 0000000000..bf1ba58641 --- /dev/null +++ b/integrationTests/diagnostics-deno-with-deno-build/deno.json @@ -0,0 +1,6 @@ +{ + "imports": { + "graphql": "../graphql-deno-dist/index.ts", + "graphql/": "../graphql-deno-dist/" + } +} diff --git a/integrationTests/diagnostics-deno-with-deno-build/package.json b/integrationTests/diagnostics-deno-with-deno-build/package.json new file mode 100644 index 0000000000..4c8d2c1d37 --- /dev/null +++ b/integrationTests/diagnostics-deno-with-deno-build/package.json @@ -0,0 +1,7 @@ +{ + "description": "graphql-js tracing channels should publish on node:diagnostics_channel (Deno with deno build)", + "private": true, + "scripts": { + "test": "docker run --rm --volume \"$PWD/..\":/usr/src/app -w /usr/src/app/diagnostics-deno-with-deno-build denoland/deno:alpine-\"$DENO_VERSION\" deno run test.js" + } +} diff --git a/integrationTests/diagnostics-deno-with-deno-build/test.js b/integrationTests/diagnostics-deno-with-deno-build/test.js new file mode 100644 index 0000000000..bcd0bbdb4f --- /dev/null +++ b/integrationTests/diagnostics-deno-with-deno-build/test.js @@ -0,0 +1,342 @@ +// TracingChannel is marked experimental in Node's docs but is shipped on +// every runtime graphql-js supports. This test exercises it directly. +/* eslint-disable n/no-unsupported-features/node-builtins */ + +import assert from 'node:assert/strict'; +import { AsyncLocalStorage } from 'node:async_hooks'; +import dc from 'node:diagnostics_channel'; + +import { buildSchema, execute, parse, subscribe, validate } from 'graphql'; + +function runParseCases() { + // graphql:parse - synchronous. + { + const events = []; + const handler = { + start: (msg) => events.push({ kind: 'start', source: msg.source }), + end: (msg) => events.push({ kind: 'end', source: msg.source }), + asyncStart: (msg) => + events.push({ kind: 'asyncStart', source: msg.source }), + asyncEnd: (msg) => events.push({ kind: 'asyncEnd', source: msg.source }), + error: (msg) => + events.push({ kind: 'error', source: msg.source, error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:parse'); + channel.subscribe(handler); + + try { + const doc = parse('{ field }'); + assert.equal(doc.kind, 'Document'); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].source, '{ field }'); + assert.equal(events[1].source, '{ field }'); + } finally { + channel.unsubscribe(handler); + } + } + + // graphql:parse - error path fires start, error, end. + { + const events = []; + const handler = { + start: (msg) => events.push({ kind: 'start', source: msg.source }), + end: (msg) => events.push({ kind: 'end', source: msg.source }), + error: (msg) => + events.push({ kind: 'error', source: msg.source, error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:parse'); + channel.subscribe(handler); + + try { + assert.throws(() => parse('{ ')); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'error', 'end'], + ); + assert.ok(events[1].error instanceof Error); + } finally { + channel.unsubscribe(handler); + } + } +} + +function runValidateCase() { + const schema = buildSchema(`type Query { field: String }`); + const doc = parse('{ field }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + document: msg.document, + }), + end: () => events.push({ kind: 'end' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:validate'); + channel.subscribe(handler); + + try { + const errors = validate(schema, doc); + assert.deepEqual(errors, []); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].schema, schema); + assert.equal(events[0].document, doc); + } finally { + channel.unsubscribe(handler); + } +} + +function runExecuteCase() { + const schema = buildSchema(`type Query { hello: String }`); + const document = parse('query Greeting { hello }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + document: msg.document, + variableValues: msg.variableValues, + operationName: msg.operationName, + operationType: msg.operationType, + }), + end: () => events.push({ kind: 'end' }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:execute'); + channel.subscribe(handler); + + try { + const result = execute({ + schema, + document, + rootValue: { hello: 'world' }, + }); + assert.equal(result.data.hello, 'world'); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].operationType, 'query'); + assert.equal(events[0].operationName, 'Greeting'); + assert.equal(events[0].document, document); + assert.equal(events[0].schema, schema); + } finally { + channel.unsubscribe(handler); + } +} + +function runExecuteRootSelectionSetCase() { + const schema = buildSchema(`type Query { hello: String }`); + const document = parse('query Greeting { hello }'); + const operation = document.definitions[0]; + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + operation: msg.operation, + variableValues: msg.variableValues, + operationName: msg.operationName, + operationType: msg.operationType, + }), + end: (msg) => events.push({ kind: 'end', result: msg.result }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:execute:rootSelectionSet'); + channel.subscribe(handler); + + try { + const result = execute({ + schema, + document, + rootValue: { hello: 'world' }, + }); + assert.equal(result.data.hello, 'world'); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].operationType, 'query'); + assert.equal(events[0].operationName, 'Greeting'); + assert.equal(events[0].operation, operation); + assert.equal(events[0].schema, schema); + assert.equal(events[1].result, result); + } finally { + channel.unsubscribe(handler); + } +} + +async function runSubscribeCase() { + async function* ticks() { + yield { tick: 'one' }; + } + + const schema = buildSchema(` + type Query { dummy: String } + type Subscription { tick: String } + `); + // buildSchema doesn't attach a subscribe resolver to fields; inject one. + schema.getSubscriptionType().getFields().tick.subscribe = () => ticks(); + + const document = parse('subscription Tick { tick }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + document: msg.document, + variableValues: msg.variableValues, + operationName: msg.operationName, + operationType: msg.operationType, + }), + end: () => events.push({ kind: 'end' }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:subscribe'); + channel.subscribe(handler); + + try { + const result = subscribe({ schema, document }); + const stream = typeof result.then === 'function' ? await result : result; + if (stream[Symbol.asyncIterator]) { + await stream.return?.(); + } + // Subscription setup is synchronous here; start/end fire, no async tail. + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].operationType, 'subscription'); + assert.equal(events[0].operationName, 'Tick'); + } finally { + channel.unsubscribe(handler); + } +} + +function runResolveCase() { + const schema = buildSchema( + `type Query { hello: String nested: Nested } type Nested { leaf: String }`, + ); + const document = parse('{ hello nested { leaf } }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + fieldName: msg.fieldName, + parentType: msg.parentType, + fieldType: msg.fieldType, + args: msg.args, + isDefaultResolver: msg.isDefaultResolver, + fieldPath: msg.fieldPath, + }), + end: () => events.push({ kind: 'end' }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:resolve'); + channel.subscribe(handler); + + try { + const rootValue = { hello: () => 'world', nested: { leaf: 'leaf-value' } }; + execute({ schema, document, rootValue }); + + const starts = events.filter((e) => e.kind === 'start'); + const paths = starts.map((e) => e.fieldPath); + assert.deepEqual(paths, ['hello', 'nested', 'nested.leaf']); + + const hello = starts.find((e) => e.fieldName === 'hello'); + assert.equal(hello.parentType, 'Query'); + assert.equal(hello.fieldType, 'String'); + // buildSchema never attaches field.resolve; all fields report as trivial. + assert.equal(hello.isDefaultResolver, true); + } finally { + channel.unsubscribe(handler); + } +} + +function runNoSubscriberCase() { + const doc = parse('{ field }'); + assert.equal(doc.kind, 'Document'); +} + +async function runAlsPropagationCase() { + // A subscriber that binds a store on the `start` sub-channel should be able + // to read it in every lifecycle handler (start, end, asyncStart, asyncEnd). + // This is what APMs use to parent child spans to the current operation + // without threading state through the context object. + const als = new AsyncLocalStorage(); + const channel = dc.tracingChannel('graphql:execute'); + channel.start.bindStore(als, (context) => ({ + operationName: context.operationName, + })); + + const seen = {}; + const handler = { + start: () => (seen.start = als.getStore()), + end: () => (seen.end = als.getStore()), + asyncStart: () => (seen.asyncStart = als.getStore()), + asyncEnd: () => (seen.asyncEnd = als.getStore()), + }; + channel.subscribe(handler); + + try { + const schema = buildSchema(`type Query { slow: String }`); + const document = parse('query Slow { slow }'); + const rootValue = { slow: () => Promise.resolve('done') }; + + await execute({ schema, document, rootValue }); + + assert.deepEqual(seen.start, { operationName: 'Slow' }); + assert.deepEqual(seen.end, { operationName: 'Slow' }); + assert.deepEqual(seen.asyncStart, { operationName: 'Slow' }); + assert.deepEqual(seen.asyncEnd, { operationName: 'Slow' }); + } finally { + channel.unsubscribe(handler); + channel.start.unbindStore(als); + } +} + +async function main() { + runParseCases(); + runValidateCase(); + runExecuteCase(); + runExecuteRootSelectionSetCase(); + await runSubscribeCase(); + runResolveCase(); + await runAlsPropagationCase(); + runNoSubscriberCase(); + console.log('diagnostics integration test passed'); +} + +main(); diff --git a/integrationTests/diagnostics-deno-with-node-build/package.json b/integrationTests/diagnostics-deno-with-node-build/package.json new file mode 100644 index 0000000000..21228b0925 --- /dev/null +++ b/integrationTests/diagnostics-deno-with-node-build/package.json @@ -0,0 +1,10 @@ +{ + "description": "graphql-js tracing channels should publish on node:diagnostics_channel (Deno with node build)", + "private": true, + "scripts": { + "test": "docker run --rm --volume \"$PWD\":/usr/src/app -w /usr/src/app denoland/deno:alpine-\"$DENO_VERSION\" deno run --conditions=development test.js" + }, + "dependencies": { + "graphql": "file:../graphql.tgz" + } +} diff --git a/integrationTests/diagnostics-deno-with-node-build/test.js b/integrationTests/diagnostics-deno-with-node-build/test.js new file mode 100644 index 0000000000..bcd0bbdb4f --- /dev/null +++ b/integrationTests/diagnostics-deno-with-node-build/test.js @@ -0,0 +1,342 @@ +// TracingChannel is marked experimental in Node's docs but is shipped on +// every runtime graphql-js supports. This test exercises it directly. +/* eslint-disable n/no-unsupported-features/node-builtins */ + +import assert from 'node:assert/strict'; +import { AsyncLocalStorage } from 'node:async_hooks'; +import dc from 'node:diagnostics_channel'; + +import { buildSchema, execute, parse, subscribe, validate } from 'graphql'; + +function runParseCases() { + // graphql:parse - synchronous. + { + const events = []; + const handler = { + start: (msg) => events.push({ kind: 'start', source: msg.source }), + end: (msg) => events.push({ kind: 'end', source: msg.source }), + asyncStart: (msg) => + events.push({ kind: 'asyncStart', source: msg.source }), + asyncEnd: (msg) => events.push({ kind: 'asyncEnd', source: msg.source }), + error: (msg) => + events.push({ kind: 'error', source: msg.source, error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:parse'); + channel.subscribe(handler); + + try { + const doc = parse('{ field }'); + assert.equal(doc.kind, 'Document'); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].source, '{ field }'); + assert.equal(events[1].source, '{ field }'); + } finally { + channel.unsubscribe(handler); + } + } + + // graphql:parse - error path fires start, error, end. + { + const events = []; + const handler = { + start: (msg) => events.push({ kind: 'start', source: msg.source }), + end: (msg) => events.push({ kind: 'end', source: msg.source }), + error: (msg) => + events.push({ kind: 'error', source: msg.source, error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:parse'); + channel.subscribe(handler); + + try { + assert.throws(() => parse('{ ')); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'error', 'end'], + ); + assert.ok(events[1].error instanceof Error); + } finally { + channel.unsubscribe(handler); + } + } +} + +function runValidateCase() { + const schema = buildSchema(`type Query { field: String }`); + const doc = parse('{ field }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + document: msg.document, + }), + end: () => events.push({ kind: 'end' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:validate'); + channel.subscribe(handler); + + try { + const errors = validate(schema, doc); + assert.deepEqual(errors, []); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].schema, schema); + assert.equal(events[0].document, doc); + } finally { + channel.unsubscribe(handler); + } +} + +function runExecuteCase() { + const schema = buildSchema(`type Query { hello: String }`); + const document = parse('query Greeting { hello }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + document: msg.document, + variableValues: msg.variableValues, + operationName: msg.operationName, + operationType: msg.operationType, + }), + end: () => events.push({ kind: 'end' }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:execute'); + channel.subscribe(handler); + + try { + const result = execute({ + schema, + document, + rootValue: { hello: 'world' }, + }); + assert.equal(result.data.hello, 'world'); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].operationType, 'query'); + assert.equal(events[0].operationName, 'Greeting'); + assert.equal(events[0].document, document); + assert.equal(events[0].schema, schema); + } finally { + channel.unsubscribe(handler); + } +} + +function runExecuteRootSelectionSetCase() { + const schema = buildSchema(`type Query { hello: String }`); + const document = parse('query Greeting { hello }'); + const operation = document.definitions[0]; + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + operation: msg.operation, + variableValues: msg.variableValues, + operationName: msg.operationName, + operationType: msg.operationType, + }), + end: (msg) => events.push({ kind: 'end', result: msg.result }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:execute:rootSelectionSet'); + channel.subscribe(handler); + + try { + const result = execute({ + schema, + document, + rootValue: { hello: 'world' }, + }); + assert.equal(result.data.hello, 'world'); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].operationType, 'query'); + assert.equal(events[0].operationName, 'Greeting'); + assert.equal(events[0].operation, operation); + assert.equal(events[0].schema, schema); + assert.equal(events[1].result, result); + } finally { + channel.unsubscribe(handler); + } +} + +async function runSubscribeCase() { + async function* ticks() { + yield { tick: 'one' }; + } + + const schema = buildSchema(` + type Query { dummy: String } + type Subscription { tick: String } + `); + // buildSchema doesn't attach a subscribe resolver to fields; inject one. + schema.getSubscriptionType().getFields().tick.subscribe = () => ticks(); + + const document = parse('subscription Tick { tick }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + document: msg.document, + variableValues: msg.variableValues, + operationName: msg.operationName, + operationType: msg.operationType, + }), + end: () => events.push({ kind: 'end' }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:subscribe'); + channel.subscribe(handler); + + try { + const result = subscribe({ schema, document }); + const stream = typeof result.then === 'function' ? await result : result; + if (stream[Symbol.asyncIterator]) { + await stream.return?.(); + } + // Subscription setup is synchronous here; start/end fire, no async tail. + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].operationType, 'subscription'); + assert.equal(events[0].operationName, 'Tick'); + } finally { + channel.unsubscribe(handler); + } +} + +function runResolveCase() { + const schema = buildSchema( + `type Query { hello: String nested: Nested } type Nested { leaf: String }`, + ); + const document = parse('{ hello nested { leaf } }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + fieldName: msg.fieldName, + parentType: msg.parentType, + fieldType: msg.fieldType, + args: msg.args, + isDefaultResolver: msg.isDefaultResolver, + fieldPath: msg.fieldPath, + }), + end: () => events.push({ kind: 'end' }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:resolve'); + channel.subscribe(handler); + + try { + const rootValue = { hello: () => 'world', nested: { leaf: 'leaf-value' } }; + execute({ schema, document, rootValue }); + + const starts = events.filter((e) => e.kind === 'start'); + const paths = starts.map((e) => e.fieldPath); + assert.deepEqual(paths, ['hello', 'nested', 'nested.leaf']); + + const hello = starts.find((e) => e.fieldName === 'hello'); + assert.equal(hello.parentType, 'Query'); + assert.equal(hello.fieldType, 'String'); + // buildSchema never attaches field.resolve; all fields report as trivial. + assert.equal(hello.isDefaultResolver, true); + } finally { + channel.unsubscribe(handler); + } +} + +function runNoSubscriberCase() { + const doc = parse('{ field }'); + assert.equal(doc.kind, 'Document'); +} + +async function runAlsPropagationCase() { + // A subscriber that binds a store on the `start` sub-channel should be able + // to read it in every lifecycle handler (start, end, asyncStart, asyncEnd). + // This is what APMs use to parent child spans to the current operation + // without threading state through the context object. + const als = new AsyncLocalStorage(); + const channel = dc.tracingChannel('graphql:execute'); + channel.start.bindStore(als, (context) => ({ + operationName: context.operationName, + })); + + const seen = {}; + const handler = { + start: () => (seen.start = als.getStore()), + end: () => (seen.end = als.getStore()), + asyncStart: () => (seen.asyncStart = als.getStore()), + asyncEnd: () => (seen.asyncEnd = als.getStore()), + }; + channel.subscribe(handler); + + try { + const schema = buildSchema(`type Query { slow: String }`); + const document = parse('query Slow { slow }'); + const rootValue = { slow: () => Promise.resolve('done') }; + + await execute({ schema, document, rootValue }); + + assert.deepEqual(seen.start, { operationName: 'Slow' }); + assert.deepEqual(seen.end, { operationName: 'Slow' }); + assert.deepEqual(seen.asyncStart, { operationName: 'Slow' }); + assert.deepEqual(seen.asyncEnd, { operationName: 'Slow' }); + } finally { + channel.unsubscribe(handler); + channel.start.unbindStore(als); + } +} + +async function main() { + runParseCases(); + runValidateCase(); + runExecuteCase(); + runExecuteRootSelectionSetCase(); + await runSubscribeCase(); + runResolveCase(); + await runAlsPropagationCase(); + runNoSubscriberCase(); + console.log('diagnostics integration test passed'); +} + +main(); diff --git a/integrationTests/diagnostics-node20/package.json b/integrationTests/diagnostics-node20/package.json new file mode 100644 index 0000000000..335e6d1eee --- /dev/null +++ b/integrationTests/diagnostics-node20/package.json @@ -0,0 +1,11 @@ +{ + "description": "graphql-js tracing channels should publish on node:diagnostics_channel (Node 20 with CJS fallback)", + "private": true, + "type": "module", + "scripts": { + "test": "docker run --rm --volume \"$PWD\":/usr/src/app -w /usr/src/app node:20.15-alpine node test.js" + }, + "dependencies": { + "graphql": "file:../graphql.tgz" + } +} diff --git a/integrationTests/diagnostics-node20/test.js b/integrationTests/diagnostics-node20/test.js new file mode 100644 index 0000000000..bcd0bbdb4f --- /dev/null +++ b/integrationTests/diagnostics-node20/test.js @@ -0,0 +1,342 @@ +// TracingChannel is marked experimental in Node's docs but is shipped on +// every runtime graphql-js supports. This test exercises it directly. +/* eslint-disable n/no-unsupported-features/node-builtins */ + +import assert from 'node:assert/strict'; +import { AsyncLocalStorage } from 'node:async_hooks'; +import dc from 'node:diagnostics_channel'; + +import { buildSchema, execute, parse, subscribe, validate } from 'graphql'; + +function runParseCases() { + // graphql:parse - synchronous. + { + const events = []; + const handler = { + start: (msg) => events.push({ kind: 'start', source: msg.source }), + end: (msg) => events.push({ kind: 'end', source: msg.source }), + asyncStart: (msg) => + events.push({ kind: 'asyncStart', source: msg.source }), + asyncEnd: (msg) => events.push({ kind: 'asyncEnd', source: msg.source }), + error: (msg) => + events.push({ kind: 'error', source: msg.source, error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:parse'); + channel.subscribe(handler); + + try { + const doc = parse('{ field }'); + assert.equal(doc.kind, 'Document'); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].source, '{ field }'); + assert.equal(events[1].source, '{ field }'); + } finally { + channel.unsubscribe(handler); + } + } + + // graphql:parse - error path fires start, error, end. + { + const events = []; + const handler = { + start: (msg) => events.push({ kind: 'start', source: msg.source }), + end: (msg) => events.push({ kind: 'end', source: msg.source }), + error: (msg) => + events.push({ kind: 'error', source: msg.source, error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:parse'); + channel.subscribe(handler); + + try { + assert.throws(() => parse('{ ')); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'error', 'end'], + ); + assert.ok(events[1].error instanceof Error); + } finally { + channel.unsubscribe(handler); + } + } +} + +function runValidateCase() { + const schema = buildSchema(`type Query { field: String }`); + const doc = parse('{ field }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + document: msg.document, + }), + end: () => events.push({ kind: 'end' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:validate'); + channel.subscribe(handler); + + try { + const errors = validate(schema, doc); + assert.deepEqual(errors, []); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].schema, schema); + assert.equal(events[0].document, doc); + } finally { + channel.unsubscribe(handler); + } +} + +function runExecuteCase() { + const schema = buildSchema(`type Query { hello: String }`); + const document = parse('query Greeting { hello }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + document: msg.document, + variableValues: msg.variableValues, + operationName: msg.operationName, + operationType: msg.operationType, + }), + end: () => events.push({ kind: 'end' }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:execute'); + channel.subscribe(handler); + + try { + const result = execute({ + schema, + document, + rootValue: { hello: 'world' }, + }); + assert.equal(result.data.hello, 'world'); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].operationType, 'query'); + assert.equal(events[0].operationName, 'Greeting'); + assert.equal(events[0].document, document); + assert.equal(events[0].schema, schema); + } finally { + channel.unsubscribe(handler); + } +} + +function runExecuteRootSelectionSetCase() { + const schema = buildSchema(`type Query { hello: String }`); + const document = parse('query Greeting { hello }'); + const operation = document.definitions[0]; + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + operation: msg.operation, + variableValues: msg.variableValues, + operationName: msg.operationName, + operationType: msg.operationType, + }), + end: (msg) => events.push({ kind: 'end', result: msg.result }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:execute:rootSelectionSet'); + channel.subscribe(handler); + + try { + const result = execute({ + schema, + document, + rootValue: { hello: 'world' }, + }); + assert.equal(result.data.hello, 'world'); + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].operationType, 'query'); + assert.equal(events[0].operationName, 'Greeting'); + assert.equal(events[0].operation, operation); + assert.equal(events[0].schema, schema); + assert.equal(events[1].result, result); + } finally { + channel.unsubscribe(handler); + } +} + +async function runSubscribeCase() { + async function* ticks() { + yield { tick: 'one' }; + } + + const schema = buildSchema(` + type Query { dummy: String } + type Subscription { tick: String } + `); + // buildSchema doesn't attach a subscribe resolver to fields; inject one. + schema.getSubscriptionType().getFields().tick.subscribe = () => ticks(); + + const document = parse('subscription Tick { tick }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + schema: msg.schema, + document: msg.document, + variableValues: msg.variableValues, + operationName: msg.operationName, + operationType: msg.operationType, + }), + end: () => events.push({ kind: 'end' }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:subscribe'); + channel.subscribe(handler); + + try { + const result = subscribe({ schema, document }); + const stream = typeof result.then === 'function' ? await result : result; + if (stream[Symbol.asyncIterator]) { + await stream.return?.(); + } + // Subscription setup is synchronous here; start/end fire, no async tail. + assert.deepEqual( + events.map((e) => e.kind), + ['start', 'end'], + ); + assert.equal(events[0].operationType, 'subscription'); + assert.equal(events[0].operationName, 'Tick'); + } finally { + channel.unsubscribe(handler); + } +} + +function runResolveCase() { + const schema = buildSchema( + `type Query { hello: String nested: Nested } type Nested { leaf: String }`, + ); + const document = parse('{ hello nested { leaf } }'); + + const events = []; + const handler = { + start: (msg) => + events.push({ + kind: 'start', + fieldName: msg.fieldName, + parentType: msg.parentType, + fieldType: msg.fieldType, + args: msg.args, + isDefaultResolver: msg.isDefaultResolver, + fieldPath: msg.fieldPath, + }), + end: () => events.push({ kind: 'end' }), + asyncStart: () => events.push({ kind: 'asyncStart' }), + asyncEnd: () => events.push({ kind: 'asyncEnd' }), + error: (msg) => events.push({ kind: 'error', error: msg.error }), + }; + + const channel = dc.tracingChannel('graphql:resolve'); + channel.subscribe(handler); + + try { + const rootValue = { hello: () => 'world', nested: { leaf: 'leaf-value' } }; + execute({ schema, document, rootValue }); + + const starts = events.filter((e) => e.kind === 'start'); + const paths = starts.map((e) => e.fieldPath); + assert.deepEqual(paths, ['hello', 'nested', 'nested.leaf']); + + const hello = starts.find((e) => e.fieldName === 'hello'); + assert.equal(hello.parentType, 'Query'); + assert.equal(hello.fieldType, 'String'); + // buildSchema never attaches field.resolve; all fields report as trivial. + assert.equal(hello.isDefaultResolver, true); + } finally { + channel.unsubscribe(handler); + } +} + +function runNoSubscriberCase() { + const doc = parse('{ field }'); + assert.equal(doc.kind, 'Document'); +} + +async function runAlsPropagationCase() { + // A subscriber that binds a store on the `start` sub-channel should be able + // to read it in every lifecycle handler (start, end, asyncStart, asyncEnd). + // This is what APMs use to parent child spans to the current operation + // without threading state through the context object. + const als = new AsyncLocalStorage(); + const channel = dc.tracingChannel('graphql:execute'); + channel.start.bindStore(als, (context) => ({ + operationName: context.operationName, + })); + + const seen = {}; + const handler = { + start: () => (seen.start = als.getStore()), + end: () => (seen.end = als.getStore()), + asyncStart: () => (seen.asyncStart = als.getStore()), + asyncEnd: () => (seen.asyncEnd = als.getStore()), + }; + channel.subscribe(handler); + + try { + const schema = buildSchema(`type Query { slow: String }`); + const document = parse('query Slow { slow }'); + const rootValue = { slow: () => Promise.resolve('done') }; + + await execute({ schema, document, rootValue }); + + assert.deepEqual(seen.start, { operationName: 'Slow' }); + assert.deepEqual(seen.end, { operationName: 'Slow' }); + assert.deepEqual(seen.asyncStart, { operationName: 'Slow' }); + assert.deepEqual(seen.asyncEnd, { operationName: 'Slow' }); + } finally { + channel.unsubscribe(handler); + channel.start.unbindStore(als); + } +} + +async function main() { + runParseCases(); + runValidateCase(); + runExecuteCase(); + runExecuteRootSelectionSetCase(); + await runSubscribeCase(); + runResolveCase(); + await runAlsPropagationCase(); + runNoSubscriberCase(); + console.log('diagnostics integration test passed'); +} + +main(); diff --git a/resources/integration-test.ts b/resources/integration-test.ts index b8e45429e3..b3616a9a42 100644 --- a/resources/integration-test.ts +++ b/resources/integration-test.ts @@ -54,6 +54,12 @@ describe('Integration Tests', () => { testOnNodeProject('node'); testOnNodeProject('webpack'); + // Tracing channel tests + testOnNodeProject('diagnostics-node20'); + testOnNodeProject('diagnostics-bun'); + testOnNodeProject('diagnostics-deno-with-deno-build'); + testOnNodeProject('diagnostics-deno-with-node-build'); + // Conditional export tests testOnNodeProject('conditions'); diff --git a/src/__testUtils__/__tests__/expectEvents-test.ts b/src/__testUtils__/__tests__/expectEvents-test.ts new file mode 100644 index 0000000000..84addbf99e --- /dev/null +++ b/src/__testUtils__/__tests__/expectEvents-test.ts @@ -0,0 +1,157 @@ +import { describe, it } from 'node:test'; + +import { expect } from 'chai'; + +import { expectEvents } from '../expectEvents.ts'; +import { expectPromise } from '../expectPromise.ts'; + +type TestTracingChannel = Parameters[0]; + +function createFakeTracingChannel(): TestTracingChannel { + let handler: + | { + start: (context: unknown) => void; + end: (context: unknown) => void; + asyncStart: (context: unknown) => void; + asyncEnd: (context: unknown) => void; + error: (context: unknown) => void; + } + | undefined; + + function runStores( + context: object, + fn: (this: object, ...args: Array) => T, + thisArg?: unknown, + ...args: Array + ): T { + return fn.apply((thisArg as object | undefined) ?? context, args); + } + + return { + hasSubscribers: false, + subscribe(nextHandler) { + handler = nextHandler; + }, + unsubscribe(nextHandler) { + expect(handler).to.equal(nextHandler); + handler = undefined; + }, + traceSync(fn, _context, thisArg, ...args) { + return fn.apply(thisArg, args); + }, + start: { + publish(context) { + handler?.start(context); + }, + runStores, + }, + end: { + publish(context) { + handler?.end(context); + }, + runStores, + }, + asyncStart: { + publish(context) { + handler?.asyncStart(context); + }, + runStores, + }, + asyncEnd: { + publish(context) { + handler?.asyncEnd(context); + }, + runStores, + }, + error: { + publish(context) { + handler?.error(context); + }, + runStores, + }, + }; +} + +describe('expectEvents', () => { + it('collects events and snapshots each published context', async () => { + const channel = createFakeTracingChannel(); + const context = { value: 1 }; + + await expectEvents( + channel, + () => { + channel.start.publish(context); + context.value = 2; + channel.end.publish(context); + return 'done'; + }, + (_result) => [ + { + channel: 'start', + context: { value: 1 }, + }, + { + channel: 'end', + context: { value: 2 }, + }, + ], + ); + }); + + it('collects events with non-object contexts', async () => { + const channel = createFakeTracingChannel(); + + await expectEvents( + channel, + () => { + channel.start.publish(null); + channel.end.publish(undefined); + channel.error.publish('error'); + return 'done'; + }, + (_result) => [ + { + channel: 'start', + context: null, + }, + { + channel: 'end', + context: undefined, + }, + { + channel: 'error', + context: 'error', + }, + ], + ); + }); + + it('unsubscribes when the callback rejects', async () => { + let activeHandler: object | undefined; + const error = new Error('boom'); + const channel = createFakeTracingChannel(); + const originalSubscribe = channel.subscribe; + const originalUnsubscribe = channel.unsubscribe; + + channel.subscribe = (handler) => { + activeHandler = handler; + originalSubscribe.call(channel, handler); + }; + channel.unsubscribe = (handler) => { + expect(handler).to.equal(activeHandler); + activeHandler = undefined; + originalUnsubscribe.call(channel, handler); + }; + + expect( + await expectPromise( + expectEvents( + channel, + () => Promise.reject(error), + () => [], + ), + ).toReject(), + ).to.equal(error); + expect(activeHandler).to.equal(undefined); + }); +}); diff --git a/src/__testUtils__/__tests__/expectNoTracingActivity-test.ts b/src/__testUtils__/__tests__/expectNoTracingActivity-test.ts new file mode 100644 index 0000000000..a9adafe47b --- /dev/null +++ b/src/__testUtils__/__tests__/expectNoTracingActivity-test.ts @@ -0,0 +1,97 @@ +import { describe, it } from 'node:test'; + +import { expect } from 'chai'; + +import { expectNoTracingActivity } from '../expectNoTracingActivity.ts'; +import { expectPromise } from '../expectPromise.ts'; + +type TestTracingChannel = Parameters[0]; + +function createFakeTracingChannel(): TestTracingChannel { + function runStores( + context: object, + fn: (this: object, ...args: Array) => T, + thisArg?: unknown, + ...args: Array + ): T { + return fn.apply((thisArg as object | undefined) ?? context, args); + } + + return { + hasSubscribers: false, + traceSync(fn, context, thisArg, ...args) { + return runStores(context, fn, thisArg, ...args); + }, + start: { + publish(_context) { + return undefined; + }, + runStores, + }, + end: { + publish(_context) { + return undefined; + }, + runStores, + }, + asyncStart: { + publish(_context) { + return undefined; + }, + runStores, + }, + asyncEnd: { + publish(_context) { + return undefined; + }, + runStores, + }, + error: { + publish(_context) { + return undefined; + }, + runStores, + }, + }; +} + +describe('expectNoTracingActivity', () => { + it('returns the callback result when no tracing methods are touched', async () => { + const channel = createFakeTracingChannel(); + + expect( + await expectNoTracingActivity(channel, () => ({ value: 'ok' })), + ).to.deep.equal({ value: 'ok' }); + }); + + it('fails and restores methods when tracing activity occurs', async () => { + const channel = createFakeTracingChannel(); + const originalPublish = channel.start.publish; + + await expectPromise( + expectNoTracingActivity(channel, () => { + channel.start.publish({ value: 1 }); + }), + ).toRejectWith("expected [ 'start.publish' ] to deeply equal []"); + + expect(channel.start.publish).to.equal(originalPublish); + }); + + it('fails when traceSync is called', async () => { + const channel = createFakeTracingChannel(); + await expectPromise( + expectNoTracingActivity(channel, () => { + channel.traceSync(() => 'ok', {}, undefined); + }), + ).toRejectWith("expected [ 'traceSync' ] to deeply equal []"); + }); + + it('fails when runStores is called', async () => { + const channel = createFakeTracingChannel(); + await expectPromise( + expectNoTracingActivity(channel, () => { + channel.start.runStores({}, () => 'ok'); + }), + ).toRejectWith("expected [ 'start.runStores' ] to deeply equal []"); + }); +}); diff --git a/src/__testUtils__/__tests__/spyOn-test.ts b/src/__testUtils__/__tests__/spyOn-test.ts index 65102dae5c..2e6208c343 100644 --- a/src/__testUtils__/__tests__/spyOn-test.ts +++ b/src/__testUtils__/__tests__/spyOn-test.ts @@ -65,4 +65,50 @@ describe('spyOnMethod', () => { "Cannot spy on 'maybeMethod' because it is not a function.", ); }); + + it('restores the original method', () => { + const obj = { + add(a: number, b: number) { + return a + b; + }, + }; + + const originalAdd = obj.add; + const spy = spyOnMethod(obj, 'add'); + + expect(obj.add).to.not.equal(originalAdd); + expect(spy.callCount).to.equal(0); + + obj.add(1, 2); + expect(spy.callCount).to.equal(1); + + spy.restore(); + + expect(obj.add).to.equal(originalAdd); + obj.add(3, 4); + expect(spy.callCount).to.equal(1); // no longer tracked + }); + + it('restores inherited methods by removing the own-property spy', () => { + class Base { + add(a: number, b: number) { + return a + b; + } + } + const instance = new Base(); + + expect(Object.hasOwn(instance, 'add')).to.equal(false); + + const spy = spyOnMethod(instance, 'add'); + expect(Object.hasOwn(instance, 'add')).to.equal(true); + + instance.add(1, 2); + expect(spy.callCount).to.equal(1); + + spy.restore(); + + expect(Object.hasOwn(instance, 'add')).to.equal(false); + instance.add(3, 4); + expect(spy.callCount).to.equal(1); // no longer tracked, prototype method again + }); }); diff --git a/src/__testUtils__/diagnosticsTracing.ts b/src/__testUtils__/diagnosticsTracing.ts new file mode 100644 index 0000000000..7de9a7c221 --- /dev/null +++ b/src/__testUtils__/diagnosticsTracing.ts @@ -0,0 +1,28 @@ +import type { MinimalChannel, MinimalTracingChannel } from '../diagnostics.ts'; + +export type TracingSubChannel = { + [Key in keyof MinimalTracingChannel]: MinimalTracingChannel[Key] extends MinimalChannel + ? Key + : never; +}[keyof MinimalTracingChannel]; + +export type TracingSubChannelRecord = { + [Channel in TracingSubChannel]: TValue; +}; + +export type TracingSubscriptionHandler = + TracingSubChannelRecord<(context: TContext) => void>; + +export type TestTracingChannel = + MinimalTracingChannel & { + subscribe: (handler: TracingSubscriptionHandler) => void; + unsubscribe: (handler: TracingSubscriptionHandler) => void; + }; + +export const tracingSubChannels: ReadonlyArray = [ + 'start', + 'end', + 'asyncStart', + 'asyncEnd', + 'error', +]; diff --git a/src/__testUtils__/expectEvents.ts b/src/__testUtils__/expectEvents.ts new file mode 100644 index 0000000000..bf6b9d142b --- /dev/null +++ b/src/__testUtils__/expectEvents.ts @@ -0,0 +1,63 @@ +import { expect } from 'chai'; + +import type { MinimalTracingChannel } from '../diagnostics.ts'; + +import type { + TestTracingChannel, + TracingSubChannel, + TracingSubChannelRecord, +} from './diagnosticsTracing.ts'; +import { tracingSubChannels } from './diagnosticsTracing.ts'; + +export type CollectedEvent = { + [Channel in TracingSubChannel]: { + channel: Channel; + context: Parameters[0]; + }; +}[TracingSubChannel]; + +export type CollectedEventFor = { + [Channel in TracingSubChannel]: { + channel: Channel; + context: TContext; + }; +}[TracingSubChannel]; + +type ExpectedEventsFactory = ( + result: Awaited, +) => ReadonlyArray>; + +/** + * Collect graphql tracing events while `fn` runs, build the expected event + * list from the callback result, and always unsubscribe before returning. + */ +export async function expectEvents( + channel: TestTracingChannel, + fn: () => TResult, + getExpectedEvents: ExpectedEventsFactory, +): Promise { + const events: Array> = []; + const handler = {} as TracingSubChannelRecord<(context: TContext) => void>; + + for (const tracingSubChannel of tracingSubChannels) { + handler[tracingSubChannel] = (context: TContext) => { + const snapshot = + typeof context === 'object' && context !== null + ? { ...context } + : context; + events.push({ + channel: tracingSubChannel, + context: snapshot, + }); + }; + } + + channel.subscribe(handler); + + try { + const resolvedResult = await fn(); + expect(events).to.deep.equal(getExpectedEvents(resolvedResult)); + } finally { + channel.unsubscribe(handler); + } +} diff --git a/src/__testUtils__/expectNoTracingActivity.ts b/src/__testUtils__/expectNoTracingActivity.ts new file mode 100644 index 0000000000..121dfa6e42 --- /dev/null +++ b/src/__testUtils__/expectNoTracingActivity.ts @@ -0,0 +1,44 @@ +import { expect } from 'chai'; + +import type { MinimalTracingChannel } from '../diagnostics.ts'; + +import { tracingSubChannels } from './diagnosticsTracing.ts'; +import type { MethodSpy } from './spyOn.ts'; +import { spyOnMethod } from './spyOn.ts'; + +/** + * Assert that a graphql tracing channel stays on its zero-subscriber fast path. + * The test installs spies around the real tracing methods and verifies none + * of them were touched while `fn` ran. + */ +export async function expectNoTracingActivity( + channel: MinimalTracingChannel, + fn: () => T | Promise, +): Promise> { + expect(channel.hasSubscribers).to.equal(false); + + const namedSpies: Array<[string, MethodSpy]> = []; + namedSpies.push(['traceSync', spyOnMethod(channel, 'traceSync')]); + + for (const phase of tracingSubChannels) { + const subChannel = channel[phase]; + namedSpies.push([`${phase}.publish`, spyOnMethod(subChannel, 'publish')]); + namedSpies.push([ + `${phase}.runStores`, + spyOnMethod(subChannel, 'runStores'), + ]); + } + + try { + const result = await fn(); + const calledMethods = namedSpies + .filter(([, spy]) => spy.callCount > 0) + .map(([name]) => name); + expect(calledMethods).to.deep.equal([]); + return result; + } finally { + for (const [, spy] of namedSpies) { + spy.restore(); + } + } +} diff --git a/src/__testUtils__/getTracingChannel.ts b/src/__testUtils__/getTracingChannel.ts new file mode 100644 index 0000000000..4a93b5bc04 --- /dev/null +++ b/src/__testUtils__/getTracingChannel.ts @@ -0,0 +1,19 @@ +/* eslint-disable n/no-unsupported-features/node-builtins */ +import dc from 'node:diagnostics_channel'; + +import type { GraphQLChannelContextByName } from '../diagnostics.ts'; + +import type { TestTracingChannel } from './diagnosticsTracing.ts'; + +/** + * Resolve a graphql tracing channel by name on the real + * `node:diagnostics_channel`. graphql-js publishes on the same channels at + * module load. + */ +export function getTracingChannel< + TName extends keyof GraphQLChannelContextByName, +>(name: TName): TestTracingChannel; +export function getTracingChannel(name: string): TestTracingChannel; +export function getTracingChannel(name: string): TestTracingChannel { + return dc.tracingChannel(name) as TestTracingChannel; +} diff --git a/src/__testUtils__/spyOn.ts b/src/__testUtils__/spyOn.ts index 934db41b2f..9ac38e3450 100644 --- a/src/__testUtils__/spyOn.ts +++ b/src/__testUtils__/spyOn.ts @@ -2,6 +2,7 @@ type AnyFn = (...args: Array) => any; export interface MethodSpy { readonly callCount: number; + restore: () => void; } export type SpyFn = T & MethodSpy; @@ -29,6 +30,7 @@ export function spyOnMethod( key: keyof T, ): MethodSpy { const original = target[key]; + const wasOwnProperty = Object.hasOwn(target, key); if (typeof original !== 'function') { throw new Error( @@ -36,7 +38,21 @@ export function spyOnMethod( ); } - const spy = spyOn(original as unknown as AnyFn); + const spy = spyOn(original as AnyFn); target[key] = spy as T[keyof T]; - return spy; + + const methodSpy: MethodSpy = { + get callCount() { + return spy.callCount; + }, + restore() { + if (wasOwnProperty) { + target[key] = original; + } else { + delete target[key]; + } + }, + }; + + return methodSpy; } diff --git a/src/__tests__/diagnostics-test.ts b/src/__tests__/diagnostics-test.ts new file mode 100644 index 0000000000..393abcd829 --- /dev/null +++ b/src/__tests__/diagnostics-test.ts @@ -0,0 +1,78 @@ +/* eslint-disable n/no-unsupported-features/node-builtins */ +import dc from 'node:diagnostics_channel'; +import { describe, it } from 'node:test'; + +import { expect } from 'chai'; + +import { invariant } from '../jsutils/invariant.ts'; + +import type { MinimalTracingChannel } from '../diagnostics.ts'; +import { + executeChannel, + executeRootSelectionSetChannel, + parseChannel, + resolveChannel, + shouldTrace, + subscribeChannel, + validateChannel, +} from '../diagnostics.ts'; + +describe('diagnostics', () => { + it('auto-registers the graphql tracing channels', () => { + invariant(parseChannel !== undefined); + invariant(validateChannel !== undefined); + invariant(executeChannel !== undefined); + invariant(executeRootSelectionSetChannel !== undefined); + invariant(subscribeChannel !== undefined); + invariant(resolveChannel !== undefined); + + // Node's `tracingChannel(name)` returns a fresh wrapper per call but + // the underlying sub-channels are cached by name, so compare those. + expect(parseChannel.start).to.equal( + dc.channel('tracing:graphql:parse:start'), + ); + expect(validateChannel.start).to.equal( + dc.channel('tracing:graphql:validate:start'), + ); + expect(executeChannel.start).to.equal( + dc.channel('tracing:graphql:execute:start'), + ); + expect(executeRootSelectionSetChannel.start).to.equal( + dc.channel('tracing:graphql:execute:rootSelectionSet:start'), + ); + expect(subscribeChannel.start).to.equal( + dc.channel('tracing:graphql:subscribe:start'), + ); + expect(resolveChannel.start).to.equal( + dc.channel('tracing:graphql:resolve:start'), + ); + }); + + describe('shouldTrace', () => { + it('returns false when channel is undefined', () => { + expect(shouldTrace(undefined)).to.equal(false); + }); + + it('reflects the aggregate hasSubscribers on a real tracing channel', () => { + const tc = dc.tracingChannel( + 'shouldTrace:aggregate', + ) as unknown as MinimalTracingChannel; + expect(shouldTrace(tc)).to.equal(false); + + const handler = { + start: () => undefined, + end: () => undefined, + asyncStart: () => undefined, + asyncEnd: () => undefined, + error: () => undefined, + }; + const realTC = dc.tracingChannel('shouldTrace:aggregate'); + realTC.subscribe(handler); + try { + expect(shouldTrace(tc)).to.equal(true); + } finally { + realTC.unsubscribe(handler); + } + }); + }); +}); diff --git a/src/diagnostics.ts b/src/diagnostics.ts new file mode 100644 index 0000000000..4164617b95 --- /dev/null +++ b/src/diagnostics.ts @@ -0,0 +1,328 @@ +/* eslint-disable no-undef, import/no-nodejs-modules, n/global-require, @typescript-eslint/no-require-imports */ +/** + * TracingChannel integration. + * + * graphql-js publishes lifecycle events on a set of named tracing channels + * that APM tools can subscribe to in order to observe parse, validate, + * execute, subscribe, and resolver behavior, plus selected executor internals. + * At module load time graphql-js resolves `node:diagnostics_channel` itself so + * APMs do not need to interact with the graphql API to enable tracing. On + * runtimes that do not expose `node:diagnostics_channel` (e.g., browsers) the + * load silently no-ops and emission sites short-circuit. + */ + +import { isPromise } from './jsutils/isPromise.ts'; +import type { Maybe } from './jsutils/Maybe.ts'; +import type { ObjMap } from './jsutils/ObjMap.ts'; + +import type { GraphQLError } from './error/GraphQLError.ts'; + +import type { + DocumentNode, + OperationDefinitionNode, + OperationTypeNode, +} from './language/ast.ts'; +import type { Source } from './language/source.ts'; + +import type { GraphQLSchema } from './type/schema.ts'; + +import type { ExecutionResult } from './execution/Executor.ts'; +import type { ExperimentalIncrementalExecutionResults } from './execution/incremental/IncrementalExecutor.ts'; + +/** + * Structural subset of `DiagnosticsChannel` sufficient for publishing and + * subscriber gating. `node:diagnostics_channel`'s `Channel` satisfies this. + * + * @internal + */ +export interface MinimalChannel { + readonly hasSubscribers?: boolean; + publish: (message: TMessage) => void; + runStores: ( + context: ContextType, + fn: (this: ContextType, ...args: Array) => T, + thisArg?: unknown, + ...args: Array + ) => T; +} + +/** + * Structural subset of Node's `TracingChannel`. The `node:diagnostics_channel` + * `TracingChannel` satisfies this by duck typing, so graphql-js does not need + * a dependency on `@types/node` or on the runtime itself. + * + * @internal + */ +export interface MinimalTracingChannel { + // `undefined` accommodates runtimes (e.g. Bun) that ship `tracingChannel` + // without exposing the aggregate `hasSubscribers` getter. + readonly hasSubscribers: boolean | undefined; + readonly start: MinimalChannel; + readonly end: MinimalChannel; + readonly asyncStart: MinimalChannel; + readonly asyncEnd: MinimalChannel; + readonly error: MinimalChannel; + + traceSync: ( + fn: (...args: Array) => T, + context: TContext extends object ? TContext : object, + thisArg?: unknown, + ...args: Array + ) => T; +} + +interface DiagnosticsChannelModule { + tracingChannel: ( + name: string, + ) => MinimalTracingChannel; +} + +/** + * Context published on `graphql:parse`. + */ +export interface GraphQLParseContext { + source: string | Source; + error?: unknown; + result?: DocumentNode; +} + +/** + * Context published on `graphql:validate`. + */ +export interface GraphQLValidateContext { + schema: GraphQLSchema; + document: DocumentNode; + error?: unknown; + result?: ReadonlyArray; +} + +/** + * Context published on `graphql:execute`. + */ +export interface GraphQLExecuteContext { + schema: GraphQLSchema; + document: DocumentNode; + variableValues: Maybe<{ readonly [variable: string]: unknown }>; + operationName: string | undefined; + operationType: OperationTypeNode | undefined; + error?: unknown; + result?: ExecutionResult | ExperimentalIncrementalExecutionResults; +} + +/** + * Context published on `graphql:execute:rootSelectionSet`. + */ +export interface GraphQLExecuteRootSelectionSetContext { + schema: GraphQLSchema; + operation: OperationDefinitionNode; + variableValues: Maybe<{ readonly [variable: string]: unknown }>; + operationName: string | undefined; + operationType: OperationTypeNode; + error?: unknown; + result?: ExecutionResult | ExperimentalIncrementalExecutionResults; +} + +/** + * Context published on `graphql:subscribe`. + */ +export interface GraphQLSubscribeContext { + schema: GraphQLSchema; + document: DocumentNode; + variableValues: Maybe<{ readonly [variable: string]: unknown }>; + operationName: string | undefined; + operationType: OperationTypeNode | undefined; + error?: unknown; + result?: AsyncGenerator | ExecutionResult; +} + +/** + * Context published on `graphql:resolve`. + */ +export interface GraphQLResolveContext { + fieldName: string; + parentType: string; + fieldType: string; + args: ObjMap; + isDefaultResolver: boolean; + fieldPath: string; + error?: unknown; + result?: unknown; +} + +export interface GraphQLChannelContextByName { + 'graphql:parse': GraphQLParseContext; + 'graphql:validate': GraphQLValidateContext; + 'graphql:execute': GraphQLExecuteContext; + 'graphql:execute:rootSelectionSet': GraphQLExecuteRootSelectionSetContext; + 'graphql:subscribe': GraphQLSubscribeContext; + 'graphql:resolve': GraphQLResolveContext; +} + +/** + * The collection of tracing channels graphql-js emits on. APMs subscribe to + * these by name on their own `node:diagnostics_channel` import; both paths + * land on the same channel instance because `tracingChannel(name)` is cached + * by name. + */ +export interface GraphQLChannels { + execute: MinimalTracingChannel; + executeRootSelectionSet: MinimalTracingChannel; + parse: MinimalTracingChannel; + validate: MinimalTracingChannel; + resolve: MinimalTracingChannel; + subscribe: MinimalTracingChannel; +} + +function resolveDiagnosticsChannel(): DiagnosticsChannelModule | undefined { + let dc: DiagnosticsChannelModule | undefined; + try { + if ( + // eslint-disable-next-line n/no-unsupported-features/node-builtins + typeof ( + globalThis as { + process?: { getBuiltinModule?: (id: string) => unknown }; + } + )?.process?.getBuiltinModule === 'function' + ) { + // eslint-disable-next-line n/no-unsupported-features/node-builtins + dc = globalThis.process.getBuiltinModule( + 'node:diagnostics_channel', + ) as DiagnosticsChannelModule; + } + // TODO: remove this code when we drop support for Node < 20.16>. + /* c8 ignore next 6 */ + if (!dc && typeof require === 'function') { + // CJS fallback for runtimes that lack `process.getBuiltinModule` + // (e.g. Node 20.0 - 20.15). ESM builds skip this branch because + // `require` is undeclared there. + dc = require('node:diagnostics_channel') as DiagnosticsChannelModule; + } + /* c8 ignore next 3 */ + } catch { + // diagnostics_channel not available on this runtime; tracing is a no-op. + } + return dc; +} + +const dc = resolveDiagnosticsChannel(); + +/** + * Per-channel handles, resolved once at module load. `undefined` when + * `node:diagnostics_channel` isn't available. Emission sites read these + * directly to keep the no-subscriber fast path to a single property access + * plus a `hasSubscribers` check (no function calls, no closures). + * + * @internal + */ +export const parseChannel: + | MinimalTracingChannel + | undefined = dc?.tracingChannel('graphql:parse'); +/** @internal */ +export const validateChannel: + | MinimalTracingChannel + | undefined = dc?.tracingChannel('graphql:validate'); +/** @internal */ +export const executeChannel: + | MinimalTracingChannel + | undefined = dc?.tracingChannel('graphql:execute'); +/** @internal */ +export const executeRootSelectionSetChannel: + | MinimalTracingChannel + | undefined = dc?.tracingChannel('graphql:execute:rootSelectionSet'); +/** @internal */ +export const subscribeChannel: + | MinimalTracingChannel + | undefined = dc?.tracingChannel('graphql:subscribe'); +/** @internal */ +export const resolveChannel: + | MinimalTracingChannel + | undefined = dc?.tracingChannel('graphql:resolve'); + +const SUB_CHANNEL_KEYS: ReadonlyArray< + 'start' | 'end' | 'asyncStart' | 'asyncEnd' | 'error' +> = ['start', 'end', 'asyncStart', 'asyncEnd', 'error']; + +/** + * Whether emission sites should publish to `channel`. Trusts the + * `TracingChannel.hasSubscribers` aggregate when the runtime exposes it; if + * the getter is missing (e.g. Bun's `node:diagnostics_channel`, where + * `tracingChannel.hasSubscribers` is `undefined`), falls back to checking + * each of the five underlying lifecycle channels so a subscriber attached + * via `tracingChannel.subscribe(handlers)` is still observed. + * + * @internal + */ +export function shouldTrace( + channel: MinimalTracingChannel | undefined, +): channel is MinimalTracingChannel { + if (channel == null) { + return false; + } + const aggregate = channel.hasSubscribers; + if (aggregate !== undefined) { + return aggregate; + /* c8 ignore start */ + } + // Bun-only fallback, exercised by integrationTests/diagnostics-bun. + for (const key of SUB_CHANNEL_KEYS) { + if (channel[key].hasSubscribers) { + return true; + } + } + return false; + /* c8 ignore stop */ +} + +/** + * Publish a mixed sync-or-promise operation through `channel`. Caller has + * already verified that a subscriber is attached. + * + * @internal + */ +export function traceMixed( + channel: MinimalTracingChannel, + contextInput: TContext extends object ? TContext : object, + fn: () => T | Promise, +): T | Promise { + const context = contextInput as TContext & { + error?: unknown; + result?: unknown; + }; + + return channel.start.runStores(context, () => { + let result: T | Promise; + try { + result = fn(); + } catch (err) { + context.error = err; + channel.error.publish(context); + channel.end.publish(context); + throw err; + } + + if (!isPromise(result)) { + context.result = result; + channel.end.publish(context); + return result; + } + + channel.end.publish(context); + channel.asyncStart.publish(context); + + return result + .then( + (value) => { + context.result = value; + return value; + }, + (err: unknown) => { + context.error = err; + channel.error.publish(context); + throw err; + }, + ) + .finally(() => { + channel.asyncEnd.publish(context); + }); + }); +} diff --git a/src/execution/Executor.ts b/src/execution/Executor.ts index c408370554..822c8b0e11 100644 --- a/src/execution/Executor.ts +++ b/src/execution/Executor.ts @@ -3,6 +3,7 @@ import { invariant } from '../jsutils/invariant.ts'; import { isAsyncIterable } from '../jsutils/isAsyncIterable.ts'; import { isIterableObject } from '../jsutils/isIterableObject.ts'; import { isPromise, isPromiseLike } from '../jsutils/isPromise.ts'; +import type { Maybe } from '../jsutils/Maybe.ts'; import { memoize2 } from '../jsutils/memoize2.ts'; import { memoize3 } from '../jsutils/memoize3.ts'; import type { ObjMap } from '../jsutils/ObjMap.ts'; @@ -45,6 +46,17 @@ import { } from '../type/definition.ts'; import type { GraphQLSchema } from '../type/schema.ts'; +import type { + GraphQLExecuteRootSelectionSetContext, + GraphQLResolveContext, +} from '../diagnostics.ts'; +import { + executeRootSelectionSetChannel, + resolveChannel, + shouldTrace, + traceMixed, +} from '../diagnostics.ts'; + import { AbortedGraphQLExecutionError } from './AbortedGraphQLExecutionError.ts'; import { buildResolveInfo } from './buildResolveInfo.ts'; import { withCancellation } from './cancellablePromise.ts'; @@ -118,6 +130,7 @@ export interface ValidatedExecutionArgs { externalAbortSignal: AbortSignal | undefined; enableEarlyExecution: boolean; hooks: ExecutionHooks | undefined; + rawVariableValues: Maybe<{ readonly [variable: string]: unknown }>; } export interface ValidatedSubscriptionArgs extends ValidatedExecutionArgs { @@ -271,6 +284,38 @@ export class Executor< executeRootSelectionSet( serially?: boolean, + ): PromiseOrValue { + if (!shouldTrace(executeRootSelectionSetChannel)) { + return this.executeRootSelectionSetImpl(serially); + } + return traceMixed( + executeRootSelectionSetChannel, + this.buildExecuteContextFromValidatedArgs(this.validatedExecutionArgs), + () => this.executeRootSelectionSetImpl(serially), + ); + } + + /** + * Build an operation-scoped diagnostics context from ValidatedExecutionArgs. + * Used after the operation has already been resolved during argument + * validation. The original document is not available at this point, only the + * resolved operation; subscribers that need the document should read it from + * the graphql:execute or graphql:subscribe contexts. + */ + buildExecuteContextFromValidatedArgs( + args: ValidatedExecutionArgs, + ): GraphQLExecuteRootSelectionSetContext { + return { + schema: args.schema, + operation: args.operation, + variableValues: args.rawVariableValues, + operationName: args.operation.name?.value, + operationType: args.operation.operation, + }; + } + + executeRootSelectionSetImpl( + serially?: boolean, ): PromiseOrValue { const externalAbortSignal = this.validatedExecutionArgs.externalAbortSignal; let removeExternalAbortListener: (() => void) | undefined; @@ -574,7 +619,18 @@ export class Executor< } const returnType = fieldDef.type; - const resolveFn = fieldDef.resolve ?? validatedExecutionArgs.fieldResolver; + let resolveFn = fieldDef.resolve ?? validatedExecutionArgs.fieldResolver; + + if (shouldTrace(resolveChannel)) { + const channel = resolveChannel; + const originalResolveFn = resolveFn; + resolveFn = (s, args, c, info) => + traceMixed( + channel, + this.buildResolveContext(args, info, fieldDef.resolve === undefined), + () => originalResolveFn(s, args, c, info), + ); + } const info = buildResolveInfo( validatedExecutionArgs, @@ -639,6 +695,32 @@ export class Executor< } } + /** + * Build a graphql:resolve channel context for a single field invocation. + * + * `fieldPath` is exposed as a lazy getter because serializing the response + * path is O(depth) and APMs that depth-filter or skip default resolvers + * often never read it. `args` is passed through by reference. + */ + buildResolveContext( + args: ObjMap, + info: GraphQLResolveInfo, + isDefaultResolver: boolean, + ): GraphQLResolveContext { + let cachedFieldPath: string | undefined; + return { + fieldName: info.fieldName, + parentType: info.parentType.name, + fieldType: String(info.returnType), + args, + isDefaultResolver, + get fieldPath() { + cachedFieldPath ??= pathToArray(info.path).join('.'); + return cachedFieldPath; + }, + }; + } + handleFieldError( rawError: unknown, returnType: GraphQLOutputType, diff --git a/src/execution/__tests__/diagnostics-execute-test.ts b/src/execution/__tests__/diagnostics-execute-test.ts new file mode 100644 index 0000000000..b110db6e0c --- /dev/null +++ b/src/execution/__tests__/diagnostics-execute-test.ts @@ -0,0 +1,484 @@ +import { describe, it } from 'node:test'; + +import { expect } from 'chai'; + +import { expectEvents } from '../../__testUtils__/expectEvents.ts'; +import { expectNoTracingActivity } from '../../__testUtils__/expectNoTracingActivity.ts'; +import { expectPromise } from '../../__testUtils__/expectPromise.ts'; +import { expectToThrow } from '../../__testUtils__/expectToThrow.ts'; +import { getTracingChannel } from '../../__testUtils__/getTracingChannel.ts'; +import { resolveOnNextTick } from '../../__testUtils__/resolveOnNextTick.ts'; + +import type { OperationDefinitionNode } from '../../language/ast.ts'; +import { OperationTypeNode } from '../../language/ast.ts'; +import { parse } from '../../language/parser.ts'; + +import { GraphQLObjectType } from '../../type/definition.ts'; +import { GraphQLString } from '../../type/scalars.ts'; +import { GraphQLSchema } from '../../type/schema.ts'; + +import { buildSchema } from '../../utilities/buildASTSchema.ts'; + +import { + execute, + executeIgnoringIncremental, + executeSync, +} from '../execute.ts'; + +const schema = buildSchema(` + type Query { + sync: String + async: String + } + + type Subscription { + tick: String + } +`); + +const executeChannel = getTracingChannel('graphql:execute'); +const executeRootSelectionSetChannel = getTracingChannel( + 'graphql:execute:rootSelectionSet', +); + +describe('execute diagnostics channel', () => { + it('emits start and end around a synchronous execute', async () => { + const document = parse('query Q($sync: String) { sync }'); + const variableValues = { sync: 'ignored by the field' }; + + await expectEvents( + executeChannel, + () => + execute({ + schema, + document, + rootValue: { sync: () => 'hello' }, + variableValues, + }), + (result) => [ + { + channel: 'start', + context: { + schema, + document, + variableValues, + operationName: 'Q', + operationType: OperationTypeNode.QUERY, + }, + }, + { + channel: 'end', + context: { + schema, + document, + variableValues, + operationName: 'Q', + operationType: OperationTypeNode.QUERY, + result, + }, + }, + ], + ); + }); + + it('emits start, end, and async lifecycle when execute returns a promise', async () => { + const document = parse('query { async }'); + + await expectEvents( + executeChannel, + () => + execute({ + schema, + document, + rootValue: { async: () => Promise.resolve('hello-async') }, + }), + (result) => [ + { + channel: 'start', + context: { + schema, + document, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.QUERY, + }, + }, + { + channel: 'end', + context: { + schema, + document, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.QUERY, + }, + }, + { + channel: 'asyncStart', + context: { + schema, + document, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.QUERY, + }, + }, + { + channel: 'asyncEnd', + context: { + schema, + document, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.QUERY, + result, + }, + }, + ], + ); + }); + + it('emits full async lifecycle with error when execute returns a rejected promise', async () => { + const asyncDeferSchema = new GraphQLSchema({ + query: new GraphQLObjectType({ + name: 'Query', + fields: { + hero: { + type: new GraphQLObjectType({ + name: 'Hero', + fields: { + id: { type: GraphQLString }, + name: { type: GraphQLString }, + }, + }), + }, + }, + }), + }); + const document = parse(` + query Deferred { + hero { name ... @defer { id } } + } + `); + + await expectEvents( + executeChannel, + () => + expectPromise( + execute({ + schema: asyncDeferSchema, + document, + rootValue: { + hero: Promise.resolve({ + id: '1', + name: async () => { + await resolveOnNextTick(); + return 'slow'; + }, + }), + }, + }), + ).toReject(), + (error) => [ + { + channel: 'start', + context: { + schema: asyncDeferSchema, + document, + variableValues: undefined, + operationName: 'Deferred', + operationType: OperationTypeNode.QUERY, + }, + }, + { + channel: 'end', + context: { + schema: asyncDeferSchema, + document, + variableValues: undefined, + operationName: 'Deferred', + operationType: OperationTypeNode.QUERY, + }, + }, + { + channel: 'asyncStart', + context: { + schema: asyncDeferSchema, + document, + variableValues: undefined, + operationName: 'Deferred', + operationType: OperationTypeNode.QUERY, + }, + }, + { + channel: 'error', + context: { + schema: asyncDeferSchema, + document, + variableValues: undefined, + operationName: 'Deferred', + operationType: OperationTypeNode.QUERY, + error, + }, + }, + { + channel: 'asyncEnd', + context: { + schema: asyncDeferSchema, + document, + variableValues: undefined, + operationName: 'Deferred', + operationType: OperationTypeNode.QUERY, + error, + }, + }, + ], + ); + }); + + it('emits once for executeSync via experimentalExecuteIncrementally', async () => { + const document = parse('{ sync }'); + + await expectEvents( + executeChannel, + () => + executeSync({ schema, document, rootValue: { sync: () => 'hello' } }), + (result) => [ + { + channel: 'start', + context: { + schema, + document, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.QUERY, + }, + }, + { + channel: 'end', + context: { + schema, + document, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.QUERY, + result, + }, + }, + ], + ); + }); + + it('emits start and end around executeIgnoringIncremental', async () => { + const document = parse('query Q { sync }'); + + await expectEvents( + executeChannel, + () => + executeIgnoringIncremental({ + schema, + document, + rootValue: { sync: () => 'hello' }, + }), + (result) => [ + { + channel: 'start', + context: { + schema, + document, + variableValues: undefined, + operationName: 'Q', + operationType: OperationTypeNode.QUERY, + }, + }, + { + channel: 'end', + context: { + schema, + document, + variableValues: undefined, + operationName: 'Q', + operationType: OperationTypeNode.QUERY, + result, + }, + }, + ], + ); + }); + + it('emits start, error, and end when execute throws synchronously', async () => { + const document = parse('{ sync }'); + const invalidSchema = buildSchema(` + directive @defer on FIELD + + type Query { + sync: String + } + `); + + await expectEvents( + executeChannel, + () => expectToThrow(() => execute({ schema: invalidSchema, document })), + (error) => [ + { + channel: 'start', + context: { + schema: invalidSchema, + document, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.QUERY, + }, + }, + { + channel: 'error', + context: { + schema: invalidSchema, + document, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.QUERY, + error, + }, + }, + { + channel: 'end', + context: { + schema: invalidSchema, + document, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.QUERY, + error, + }, + }, + ], + ); + }); + + it('does not call tracing methods when no subscribers are attached', async () => { + const document = parse('{ sync }'); + const result = await expectNoTracingActivity(executeChannel, () => + execute({ + schema, + document, + rootValue: { sync: () => 'hello' }, + }), + ); + expect(result).to.deep.equal({ data: { sync: 'hello' } }); + }); +}); + +describe('execute root selection set diagnostics channel', () => { + it('emits start and end around a synchronous root selection set', async () => { + const document = parse('query Q($sync: String) { sync }'); + const operation = document.definitions[0] as OperationDefinitionNode; + const variableValues = { sync: 'ignored by the field' }; + + await expectEvents( + executeRootSelectionSetChannel, + () => + execute({ + schema, + document, + rootValue: { sync: () => 'hello' }, + variableValues, + }), + (result) => [ + { + channel: 'start', + context: { + schema, + operation, + variableValues, + operationName: 'Q', + operationType: OperationTypeNode.QUERY, + }, + }, + { + channel: 'end', + context: { + schema, + operation, + variableValues, + operationName: 'Q', + operationType: OperationTypeNode.QUERY, + result, + }, + }, + ], + ); + }); + + it('emits the full async lifecycle when the root selection set returns a promise', async () => { + const document = parse('query { async }'); + const operation = document.definitions[0] as OperationDefinitionNode; + + await expectEvents( + executeRootSelectionSetChannel, + () => + execute({ + schema, + document, + rootValue: { async: () => Promise.resolve('hello-async') }, + }), + (result) => [ + { + channel: 'start', + context: { + schema, + operation, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.QUERY, + }, + }, + { + channel: 'end', + context: { + schema, + operation, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.QUERY, + }, + }, + { + channel: 'asyncStart', + context: { + schema, + operation, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.QUERY, + }, + }, + { + channel: 'asyncEnd', + context: { + schema, + operation, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.QUERY, + result, + }, + }, + ], + ); + }); + + it('does not call tracing methods when no subscribers are attached', async () => { + const document = parse('{ sync }'); + const result = await expectNoTracingActivity( + executeRootSelectionSetChannel, + () => + execute({ + schema, + document, + rootValue: { sync: () => 'hello' }, + }), + ); + expect(result).to.deep.equal({ data: { sync: 'hello' } }); + }); +}); diff --git a/src/execution/__tests__/diagnostics-resolve-test.ts b/src/execution/__tests__/diagnostics-resolve-test.ts new file mode 100644 index 0000000000..d05a5d28ff --- /dev/null +++ b/src/execution/__tests__/diagnostics-resolve-test.ts @@ -0,0 +1,600 @@ +import { describe, it } from 'node:test'; + +import { expect } from 'chai'; + +import { expectEvents } from '../../__testUtils__/expectEvents.ts'; +import { expectNoTracingActivity } from '../../__testUtils__/expectNoTracingActivity.ts'; +import { getTracingChannel } from '../../__testUtils__/getTracingChannel.ts'; + +import { parse } from '../../language/parser.ts'; + +import { GraphQLObjectType } from '../../type/definition.ts'; +import { GraphQLString } from '../../type/scalars.ts'; +import { GraphQLSchema } from '../../type/schema.ts'; + +import { buildSchema } from '../../utilities/buildASTSchema.ts'; + +import { execute } from '../execute.ts'; + +const schema = buildSchema(` + type Query { + sync: String + async: String + fail: String + asyncFail: String + plain: String + nested: Nested + } + + type Nested { + leaf: String + } + + type Mutation { + first: String + second: String + } +`); + +const resolveChannel = getTracingChannel('graphql:resolve'); + +describe('resolve diagnostics channel', () => { + it('emits start and end around a synchronous resolver', async () => { + const document = parse('{ sync }'); + + await expectEvents( + resolveChannel, + () => + execute({ + schema, + document, + rootValue: { sync: () => 'hello' }, + }), + () => [ + { + channel: 'start', + context: { + fieldName: 'sync', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'sync', + }, + }, + { + channel: 'end', + context: { + fieldName: 'sync', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'sync', + result: 'hello', + }, + }, + ], + ); + }); + + it('emits the full async lifecycle when a resolver returns a promise', async () => { + const document = parse('{ async }'); + + await expectEvents( + resolveChannel, + () => + execute({ + schema, + document, + rootValue: { async: () => Promise.resolve('hello-async') }, + }), + () => [ + { + channel: 'start', + context: { + fieldName: 'async', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'async', + }, + }, + { + channel: 'end', + context: { + fieldName: 'async', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'async', + }, + }, + { + channel: 'asyncStart', + context: { + fieldName: 'async', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'async', + }, + }, + { + channel: 'asyncEnd', + context: { + fieldName: 'async', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'async', + result: 'hello-async', + }, + }, + ], + ); + }); + + it('emits start, error, end when a sync resolver throws', async () => { + const document = parse('{ fail }'); + const error = new Error('boom'); + + await expectEvents( + resolveChannel, + () => + execute({ + schema, + document, + rootValue: { + fail: () => { + throw error; + }, + }, + }), + () => [ + { + channel: 'start', + context: { + fieldName: 'fail', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'fail', + }, + }, + { + channel: 'error', + context: { + fieldName: 'fail', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'fail', + error, + }, + }, + { + channel: 'end', + context: { + fieldName: 'fail', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'fail', + error, + }, + }, + ], + ); + }); + + it('emits full async lifecycle with error when a resolver rejects', async () => { + const document = parse('{ asyncFail }'); + const error = new Error('async-boom'); + + await expectEvents( + resolveChannel, + () => + execute({ + schema, + document, + rootValue: { + asyncFail: () => Promise.reject(error), + }, + }), + () => [ + { + channel: 'start', + context: { + fieldName: 'asyncFail', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'asyncFail', + }, + }, + { + channel: 'end', + context: { + fieldName: 'asyncFail', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'asyncFail', + }, + }, + { + channel: 'asyncStart', + context: { + fieldName: 'asyncFail', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'asyncFail', + }, + }, + { + channel: 'error', + context: { + fieldName: 'asyncFail', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'asyncFail', + error, + }, + }, + { + channel: 'asyncEnd', + context: { + fieldName: 'asyncFail', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'asyncFail', + error, + }, + }, + ], + ); + }); + + it('reports isDefaultResolver based on field.resolve presence', async () => { + const trivialSchema = new GraphQLSchema({ + query: new GraphQLObjectType({ + name: 'Query', + fields: { + trivial: { type: GraphQLString }, + custom: { + type: GraphQLString, + resolve: () => 'explicit', + }, + }, + }), + }); + + await expectEvents( + resolveChannel, + () => + execute({ + schema: trivialSchema, + document: parse('{ trivial custom }'), + rootValue: { trivial: 'value' }, + }), + () => [ + { + channel: 'start', + context: { + fieldName: 'trivial', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'trivial', + }, + }, + { + channel: 'end', + context: { + fieldName: 'trivial', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'trivial', + result: 'value', + }, + }, + { + channel: 'start', + context: { + fieldName: 'custom', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: false, + fieldPath: 'custom', + }, + }, + { + channel: 'end', + context: { + fieldName: 'custom', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: false, + fieldPath: 'custom', + result: 'explicit', + }, + }, + ], + ); + }); + + it('serializes fieldPath lazily, joining path keys with dots', async () => { + const document = parse('{ nested { leaf } }'); + const nested = { leaf: 'leaf-value' }; + + await expectEvents( + resolveChannel, + () => + execute({ + schema, + document, + rootValue: { + nested, + }, + }), + () => [ + { + channel: 'start', + context: { + fieldName: 'nested', + parentType: 'Query', + fieldType: 'Nested', + args: {}, + isDefaultResolver: true, + fieldPath: 'nested', + }, + }, + { + channel: 'end', + context: { + fieldName: 'nested', + parentType: 'Query', + fieldType: 'Nested', + args: {}, + isDefaultResolver: true, + fieldPath: 'nested', + result: nested, + }, + }, + { + channel: 'start', + context: { + fieldName: 'leaf', + parentType: 'Nested', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'nested.leaf', + }, + }, + { + channel: 'end', + context: { + fieldName: 'leaf', + parentType: 'Nested', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'nested.leaf', + result: 'leaf-value', + }, + }, + ], + ); + }); + + it('fires once per field, not per schema walk', async () => { + const document = parse('{ sync plain nested { leaf } }'); + const nested = { leaf: 'leaf-value' }; + + await expectEvents( + resolveChannel, + () => + execute({ + schema, + document, + rootValue: { + sync: () => 'hello', + plain: 'plain-value', + nested, + }, + }), + () => [ + { + channel: 'start', + context: { + fieldName: 'sync', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'sync', + }, + }, + { + channel: 'end', + context: { + fieldName: 'sync', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'sync', + result: 'hello', + }, + }, + { + channel: 'start', + context: { + fieldName: 'plain', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'plain', + }, + }, + { + channel: 'end', + context: { + fieldName: 'plain', + parentType: 'Query', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'plain', + result: 'plain-value', + }, + }, + { + channel: 'start', + context: { + fieldName: 'nested', + parentType: 'Query', + fieldType: 'Nested', + args: {}, + isDefaultResolver: true, + fieldPath: 'nested', + }, + }, + { + channel: 'end', + context: { + fieldName: 'nested', + parentType: 'Query', + fieldType: 'Nested', + args: {}, + isDefaultResolver: true, + fieldPath: 'nested', + result: nested, + }, + }, + { + channel: 'start', + context: { + fieldName: 'leaf', + parentType: 'Nested', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'nested.leaf', + }, + }, + { + channel: 'end', + context: { + fieldName: 'leaf', + parentType: 'Nested', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'nested.leaf', + result: 'leaf-value', + }, + }, + ], + ); + }); + + it('emits per-field for serial mutation execution', async () => { + const document = parse('mutation M { first second }'); + + await expectEvents( + resolveChannel, + () => + execute({ + schema, + document, + rootValue: { + first: () => 'one', + second: () => 'two', + }, + }), + () => [ + { + channel: 'start', + context: { + fieldName: 'first', + parentType: 'Mutation', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'first', + }, + }, + { + channel: 'end', + context: { + fieldName: 'first', + parentType: 'Mutation', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'first', + result: 'one', + }, + }, + { + channel: 'start', + context: { + fieldName: 'second', + parentType: 'Mutation', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'second', + }, + }, + { + channel: 'end', + context: { + fieldName: 'second', + parentType: 'Mutation', + fieldType: 'String', + args: {}, + isDefaultResolver: true, + fieldPath: 'second', + result: 'two', + }, + }, + ], + ); + }); + + it('does not call tracing methods when no subscribers are attached', async () => { + const result = await expectNoTracingActivity(resolveChannel, () => + execute({ + schema, + document: parse('{ sync }'), + rootValue: { sync: () => 'hello' }, + }), + ); + expect(result).to.deep.equal({ data: { sync: 'hello' } }); + }); +}); diff --git a/src/execution/__tests__/diagnostics-subscribe-test.ts b/src/execution/__tests__/diagnostics-subscribe-test.ts new file mode 100644 index 0000000000..ee74071379 --- /dev/null +++ b/src/execution/__tests__/diagnostics-subscribe-test.ts @@ -0,0 +1,503 @@ +import { describe, it } from 'node:test'; + +import { assert, expect } from 'chai'; + +import { expectEvents } from '../../__testUtils__/expectEvents.ts'; +import { expectNoTracingActivity } from '../../__testUtils__/expectNoTracingActivity.ts'; +import { expectToThrow } from '../../__testUtils__/expectToThrow.ts'; +import { getTracingChannel } from '../../__testUtils__/getTracingChannel.ts'; + +import { isAsyncIterable } from '../../jsutils/isAsyncIterable.ts'; + +import type { OperationDefinitionNode } from '../../language/ast.ts'; +import { OperationTypeNode } from '../../language/ast.ts'; +import { parse } from '../../language/parser.ts'; + +import type { GraphQLSchema } from '../../type/schema.ts'; + +import { buildSchema } from '../../utilities/buildASTSchema.ts'; + +import { + createSourceEventStream, + executeSubscriptionEvent, + mapSourceToResponseEvent, + subscribe, + validateSubscriptionArgs, +} from '../execute.ts'; + +const schema = buildSchema(` + type Query { + dummy: String + } + + type Subscription { + tick: String + } +`); + +const subscribeChannel = getTracingChannel('graphql:subscribe'); +const executeRootSelectionSetChannel = getTracingChannel( + 'graphql:execute:rootSelectionSet', +); + +async function* twoTicks(): AsyncIterable<{ tick: string }> { + await Promise.resolve(); + yield { tick: 'one' }; + yield { tick: 'two' }; +} + +describe('subscribe diagnostics channel', () => { + it('emits start and end for a synchronous subscription setup', async () => { + const document = parse('subscription S($tick: String) { tick }'); + const variableValues = { tick: 'ignored by the field' }; + + await expectEvents( + subscribeChannel, + async () => { + const subscription = await subscribe({ + schema, + document, + rootValue: { tick: twoTicks }, + variableValues, + }); + assert(isAsyncIterable(subscription)); + + const returned = subscription.return?.(); + if (returned !== undefined) { + await returned; + } + return subscription; + }, + (result) => [ + { + channel: 'start', + context: { + schema, + document, + variableValues, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + }, + }, + { + channel: 'end', + context: { + schema, + document, + variableValues, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + result, + }, + }, + ], + ); + }); + + it('emits the full async lifecycle when subscribe resolver returns a promise', async () => { + const document = parse('subscription { tick }'); + + await expectEvents( + subscribeChannel, + async () => { + const subscription = await subscribe({ + schema, + document, + rootValue: { + tick: (): Promise> => + Promise.resolve(twoTicks()), + }, + }); + assert(isAsyncIterable(subscription)); + + const returned = subscription.return?.(); + if (returned !== undefined) { + await returned; + } + return subscription; + }, + (result) => [ + { + channel: 'start', + context: { + schema, + document, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.SUBSCRIPTION, + }, + }, + { + channel: 'end', + context: { + schema, + document, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.SUBSCRIPTION, + }, + }, + { + channel: 'asyncStart', + context: { + schema, + document, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.SUBSCRIPTION, + }, + }, + { + channel: 'asyncEnd', + context: { + schema, + document, + variableValues: undefined, + operationName: undefined, + operationType: OperationTypeNode.SUBSCRIPTION, + result, + }, + }, + ], + ); + }); + + it('emits execute root selection set events for each event with the default per-event executor', async () => { + const document = parse('subscription S($tick: String) { tick }'); + const operation = document.definitions[0] as OperationDefinitionNode; + const variableValues = { tick: 'ignored by the field' }; + + await expectEvents( + executeRootSelectionSetChannel, + async () => { + const subscription = await subscribe({ + schema, + document, + rootValue: { tick: twoTicks }, + variableValues, + }); + assert(isAsyncIterable(subscription)); + + const firstResult = await subscription.next(); + expect(firstResult).to.deep.equal({ + done: false, + value: { data: { tick: 'one' } }, + }); + assert(!firstResult.done, 'Expected first subscription event.'); + const secondResult = await subscription.next(); + expect(secondResult).to.deep.equal({ + done: false, + value: { data: { tick: 'two' } }, + }); + assert(!secondResult.done, 'Expected second subscription event.'); + + const returned = subscription.return?.(); + if (returned !== undefined) { + await returned; + } + return [firstResult.value, secondResult.value] as const; + }, + ([firstResult, secondResult]) => [ + { + channel: 'start', + context: { + schema, + operation, + variableValues, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + }, + }, + { + channel: 'end', + context: { + schema, + operation, + variableValues, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + result: firstResult, + }, + }, + { + channel: 'start', + context: { + schema, + operation, + variableValues, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + }, + }, + { + channel: 'end', + context: { + schema, + operation, + variableValues, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + result: secondResult, + }, + }, + ], + ); + }); + + it('emits execute root selection set events for each event with a custom per-event executor', async () => { + const document = parse('subscription S($tick: String) { tick }'); + const operation = document.definitions[0] as OperationDefinitionNode; + const variableValues = { tick: 'ignored by the field' }; + + await expectEvents( + executeRootSelectionSetChannel, + async () => { + const validatedArgs = validateSubscriptionArgs({ + schema, + document, + rootValue: { tick: twoTicks }, + variableValues, + }); + if (!('schema' in validatedArgs)) { + throw new Error('Unexpected validation errors'); + } + + const sourceEventStream = await createSourceEventStream(validatedArgs); + assert(isAsyncIterable(sourceEventStream)); + + const customExecutor: typeof executeSubscriptionEvent = (args) => + executeSubscriptionEvent(args); + + const responseStream = mapSourceToResponseEvent( + validatedArgs, + sourceEventStream, + customExecutor, + ); + + const firstResult = await responseStream.next(); + expect(firstResult).to.deep.equal({ + done: false, + value: { data: { tick: 'one' } }, + }); + assert(!firstResult.done, 'Expected first subscription event.'); + const secondResult = await responseStream.next(); + expect(secondResult).to.deep.equal({ + done: false, + value: { data: { tick: 'two' } }, + }); + assert(!secondResult.done, 'Expected second subscription event.'); + + const returned = responseStream.return?.(); + if (returned !== undefined) { + await returned; + } + return [firstResult.value, secondResult.value] as const; + }, + ([firstResult, secondResult]) => [ + { + channel: 'start', + context: { + schema, + operation, + variableValues, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + }, + }, + { + channel: 'end', + context: { + schema, + operation, + variableValues, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + result: firstResult, + }, + }, + { + channel: 'start', + context: { + schema, + operation, + variableValues, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + }, + }, + { + channel: 'end', + context: { + schema, + operation, + variableValues, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + result: secondResult, + }, + }, + ], + ); + }); + + it('emits only start and end for a synchronous validation failure', async () => { + const document = parse('fragment F on Subscription { tick }'); + + await expectEvents( + subscribeChannel, + async () => { + const result = await subscribe({ schema, document }); + expect(result).to.have.property('errors'); + return result; + }, + (result) => [ + { + channel: 'start', + context: { + schema, + document, + variableValues: undefined, + operationName: undefined, + operationType: undefined, + }, + }, + { + channel: 'end', + context: { + schema, + document, + variableValues: undefined, + operationName: undefined, + operationType: undefined, + result, + }, + }, + ], + ); + }); + + it('emits start, error, and end when subscribe throws synchronously', async () => { + const document = parse('subscription S { tick }'); + const invalidSchema = {} as GraphQLSchema; + + await expectEvents( + subscribeChannel, + () => expectToThrow(() => subscribe({ schema: invalidSchema, document })), + (error) => [ + { + channel: 'start', + context: { + schema: invalidSchema, + document, + variableValues: undefined, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + }, + }, + { + channel: 'error', + context: { + schema: invalidSchema, + document, + variableValues: undefined, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + error, + }, + }, + { + channel: 'end', + context: { + schema: invalidSchema, + document, + variableValues: undefined, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + error, + }, + }, + ], + ); + }); + + it('emits full async lifecycle when subscribe resolver rejects and subscribe resolves to an error result', async () => { + const document = parse('subscription S { tick }'); + const error = new Error('subscribe-boom'); + + await expectEvents( + subscribeChannel, + async () => { + const result = await subscribe({ + schema, + document, + rootValue: { + tick: () => Promise.reject(error), + }, + }); + expect(result).to.have.property('errors'); + return result; + }, + (result) => [ + { + channel: 'start', + context: { + schema, + document, + variableValues: undefined, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + }, + }, + { + channel: 'end', + context: { + schema, + document, + variableValues: undefined, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + }, + }, + { + channel: 'asyncStart', + context: { + schema, + document, + variableValues: undefined, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + }, + }, + { + channel: 'asyncEnd', + context: { + schema, + document, + variableValues: undefined, + operationName: 'S', + operationType: OperationTypeNode.SUBSCRIPTION, + result, + }, + }, + ], + ); + }); + + it('does not call tracing methods when no subscribers are attached', async () => { + const document = parse('subscription { tick }'); + + await expectNoTracingActivity(subscribeChannel, async () => { + const resolved = await subscribe({ + schema, + document, + rootValue: { tick: twoTicks }, + }); + assert(isAsyncIterable(resolved)); + + const returned = resolved.return?.(); + if (returned !== undefined) { + await returned; + } + }); + }); +}); diff --git a/src/execution/execute.ts b/src/execution/execute.ts index 6cc412cd77..b498277d3e 100644 --- a/src/execution/execute.ts +++ b/src/execution/execute.ts @@ -28,6 +28,16 @@ import type { import { assertValidSchema } from '../type/index.ts'; import type { GraphQLSchema } from '../type/schema.ts'; +import { getOperationAST } from '../utilities/getOperationAST.ts'; + +import type { GraphQLExecuteContext } from '../diagnostics.ts'; +import { + executeChannel, + shouldTrace, + subscribeChannel, + traceMixed, +} from '../diagnostics.ts'; + import { buildResolveInfo } from './buildResolveInfo.ts'; import { cancellablePromise } from './cancellablePromise.ts'; import type { FieldDetailsList, FragmentDetails } from './collectFields.ts'; @@ -71,12 +81,48 @@ export type RootSelectionSetExecutor = ( * delivery. */ export function execute(args: ExecutionArgs): PromiseOrValue { + if (!shouldTrace(executeChannel)) { + return executeImpl(args); + } + return traceMixed(executeChannel, buildOperationContextFromArgs(args), () => + executeImpl(args), + ); +} + +/** + * Build a graphql:execute channel context from raw ExecutionArgs. Defers + * resolution of the operation AST to a lazy getter so the cost of walking + * the document is only paid if a subscriber reads it. + */ +function buildOperationContextFromArgs( + args: ExecutionArgs, +): Omit { + let operation: OperationDefinitionNode | null | undefined; + const resolveOperation = (): OperationDefinitionNode | null | undefined => { + if (operation === undefined) { + operation = getOperationAST(args.document, args.operationName); + } + return operation; + }; + return { + schema: args.schema, + document: args.document, + variableValues: args.variableValues, + get operationName() { + return args.operationName ?? resolveOperation()?.name?.value; + }, + get operationType() { + return resolveOperation()?.operation; + }, + }; +} + +function executeImpl(args: ExecutionArgs): PromiseOrValue { if (args.schema.getDirective('defer') || args.schema.getDirective('stream')) { throw new Error(UNEXPECTED_EXPERIMENTAL_DIRECTIVES); } const validatedExecutionArgs = validateExecutionArgs(args); - // Return early errors if execution context failed. if (!('schema' in validatedExecutionArgs)) { return { errors: validatedExecutionArgs }; @@ -100,10 +146,20 @@ export function execute(args: ExecutionArgs): PromiseOrValue { export function experimentalExecuteIncrementally( args: ExecutionArgs, ): PromiseOrValue { - // If a valid execution context cannot be created due to incorrect arguments, - // a "Response" with only errors is returned. - const validatedExecutionArgs = validateExecutionArgs(args); + if (!shouldTrace(executeChannel)) { + return experimentalExecuteIncrementallyImpl(args); + } + return traceMixed(executeChannel, buildOperationContextFromArgs(args), () => + experimentalExecuteIncrementallyImpl(args), + ); +} +function experimentalExecuteIncrementallyImpl( + args: ExecutionArgs, +): PromiseOrValue { + // If a valid execution context cannot be created due to incorrect + // arguments, a "Response" with only errors is returned. + const validatedExecutionArgs = validateExecutionArgs(args); // Return early errors if execution context failed. if (!('schema' in validatedExecutionArgs)) { return { errors: validatedExecutionArgs }; @@ -115,10 +171,20 @@ export function experimentalExecuteIncrementally( export function executeIgnoringIncremental( args: ExecutionArgs, ): PromiseOrValue { - // If a valid execution context cannot be created due to incorrect arguments, - // a "Response" with only errors is returned. - const validatedExecutionArgs = validateExecutionArgs(args); + if (!shouldTrace(executeChannel)) { + return executeIgnoringIncrementalImpl(args); + } + return traceMixed(executeChannel, buildOperationContextFromArgs(args), () => + executeIgnoringIncrementalImpl(args), + ); +} +function executeIgnoringIncrementalImpl( + args: ExecutionArgs, +): PromiseOrValue { + // If a valid execution context cannot be created due to incorrect + // arguments, a "Response" with only errors is returned. + const validatedExecutionArgs = validateExecutionArgs(args); // Return early errors if execution context failed. if (!('schema' in validatedExecutionArgs)) { return { errors: validatedExecutionArgs }; @@ -219,8 +285,21 @@ export function subscribe( ): PromiseOrValue< AsyncGenerator | ExecutionResult > { - // If a valid execution context cannot be created due to incorrect arguments, - // a "Response" with only errors is returned. + if (!shouldTrace(subscribeChannel)) { + return subscribeImpl(args); + } + return traceMixed(subscribeChannel, buildOperationContextFromArgs(args), () => + subscribeImpl(args), + ); +} + +function subscribeImpl( + args: ExecutionArgs, +): PromiseOrValue< + AsyncGenerator | ExecutionResult +> { + // If a valid execution context cannot be created due to incorrect + // arguments, a "Response" with only errors is returned. const validatedExecutionArgs = validateSubscriptionArgs(args); // Return early errors if execution context failed. @@ -433,6 +512,7 @@ export function validateExecutionArgs( externalAbortSignal: externalAbortSignal ?? undefined, enableEarlyExecution: enableEarlyExecution === true, hooks: hooks ?? undefined, + rawVariableValues: rawVariableValues ?? undefined, }; } @@ -544,8 +624,6 @@ export function mapSourceToResponseEvent( sourceEventStream: AsyncIterable, rootSelectionSetExecutor: RootSelectionSetExecutor = executeSubscriptionEvent, ): AsyncGenerator { - // For each payload yielded from a subscription, map it over the normal - // GraphQL `execute` function, with `payload` as the rootValue. function mapFn(payload: unknown): PromiseOrValue { const perEventExecutionArgs: ValidatedSubscriptionArgs = { ...validatedExecutionArgs, diff --git a/src/index.ts b/src/index.ts index 7232871e9d..d93eefd305 100644 --- a/src/index.ts +++ b/src/index.ts @@ -32,6 +32,20 @@ export { version, versionInfo } from './version.ts'; // Enable development mode for additional checks. export { enableDevMode, isDevModeEnabled } from './devMode.ts'; +// Tracing channel types for subscribers that want to strongly type the +// `graphql:*` channel context payloads. Channels are auto-registered on +// `node:diagnostics_channel` at module load. +export type { + GraphQLChannelContextByName, + GraphQLChannels, + GraphQLExecuteContext, + GraphQLExecuteRootSelectionSetContext, + GraphQLParseContext, + GraphQLResolveContext, + GraphQLSubscribeContext, + GraphQLValidateContext, +} from './diagnostics.ts'; + // The primary entry point into fulfilling a GraphQL request. export type { GraphQLArgs } from './graphql.ts'; export { graphql, graphqlSync } from './graphql.ts'; diff --git a/src/language/__tests__/diagnostics-test.ts b/src/language/__tests__/diagnostics-test.ts new file mode 100644 index 0000000000..d6b3a1cb6a --- /dev/null +++ b/src/language/__tests__/diagnostics-test.ts @@ -0,0 +1,54 @@ +import { describe, it } from 'node:test'; + +import { expect } from 'chai'; + +import { expectEvents } from '../../__testUtils__/expectEvents.ts'; +import { expectNoTracingActivity } from '../../__testUtils__/expectNoTracingActivity.ts'; +import { expectToThrow } from '../../__testUtils__/expectToThrow.ts'; +import { getTracingChannel } from '../../__testUtils__/getTracingChannel.ts'; + +import { parse } from '../parser.ts'; + +const parseChannel = getTracingChannel('graphql:parse'); + +describe('parse diagnostics channel', () => { + it('emits start and end around a successful parse', async () => { + const source = '{ field }'; + + await expectEvents( + parseChannel, + () => parse(source), + (result) => [ + { channel: 'start', context: { source } }, + { channel: 'end', context: { source, result } }, + ], + ); + }); + + it('emits start, error, and end when the parser throws', async () => { + const source = '{ '; + + await expectEvents( + parseChannel, + () => expectToThrow(() => parse(source)), + (error) => [ + { channel: 'start', context: { source } }, + { + channel: 'error', + context: { + source, + error, + }, + }, + { channel: 'end', context: { source, error } }, + ], + ); + }); + + it('does not call tracing methods when no subscribers are attached', async () => { + const document = await expectNoTracingActivity(parseChannel, () => + parse('{ field }'), + ); + expect(document.kind).to.equal('Document'); + }); +}); diff --git a/src/language/parser.ts b/src/language/parser.ts index 2948479d6a..5108078b08 100644 --- a/src/language/parser.ts +++ b/src/language/parser.ts @@ -3,6 +3,8 @@ import type { Maybe } from '../jsutils/Maybe.ts'; import type { GraphQLError } from '../error/GraphQLError.ts'; import { syntaxError } from '../error/syntaxError.ts'; +import { parseChannel, shouldTrace } from '../diagnostics.ts'; + import type { ArgumentCoordinateNode, ArgumentNode, @@ -144,6 +146,15 @@ export interface ParseOptions { export function parse( source: string | Source, options?: ParseOptions, +): DocumentNode { + return shouldTrace(parseChannel) + ? parseChannel.traceSync(() => parseImpl(source, options), { source }) + : parseImpl(source, options); +} + +function parseImpl( + source: string | Source, + options: ParseOptions | undefined, ): DocumentNode { const parser = new Parser(source, options); const document = parser.parseDocument(); diff --git a/src/type/validate.ts b/src/type/validate.ts index fe0f8de4dc..9597b2d2e2 100644 --- a/src/type/validate.ts +++ b/src/type/validate.ts @@ -742,7 +742,7 @@ function validateOneOfInputObjectField( function createInputObjectNonNullCircularRefsValidator( context: SchemaValidationContext, ): (inputObj: GraphQLInputObjectType) => void { - // Modified copy of algorithm from 'src/validation/rules/NoFragmentCycles.js'. + // Modified copy of algorithm from 'src/validation/rules/NoFragmentCycles.ts'. // Tracks already visited types to maintain O(N) and to ensure that cycles // are not redundantly reported. const visitedTypes = new Set(); @@ -804,7 +804,7 @@ function createInputObjectNonNullCircularRefsValidator( function createInputObjectDefaultValueCircularRefsValidator( context: SchemaValidationContext, ): (inputObj: GraphQLInputObjectType) => void { - // Modified copy of algorithm from 'src/validation/rules/NoFragmentCycles.js'. + // Modified copy of algorithm from 'src/validation/rules/NoFragmentCycles.ts'. // Tracks already visited types to maintain O(N) and to ensure that cycles // are not redundantly reported. const visitedFields = Object.create(null); diff --git a/src/validation/__tests__/diagnostics-test.ts b/src/validation/__tests__/diagnostics-test.ts new file mode 100644 index 0000000000..3029617c63 --- /dev/null +++ b/src/validation/__tests__/diagnostics-test.ts @@ -0,0 +1,88 @@ +import { describe, it } from 'node:test'; + +import { expect } from 'chai'; + +import { expectEvents } from '../../__testUtils__/expectEvents.ts'; +import { expectNoTracingActivity } from '../../__testUtils__/expectNoTracingActivity.ts'; +import { expectToThrow } from '../../__testUtils__/expectToThrow.ts'; +import { getTracingChannel } from '../../__testUtils__/getTracingChannel.ts'; + +import { parse } from '../../language/parser.ts'; + +import type { GraphQLSchema } from '../../type/schema.ts'; + +import { buildSchema } from '../../utilities/buildASTSchema.ts'; + +import { validate } from '../validate.ts'; + +const schema = buildSchema(` + type Query { + field: String + } +`); + +const validateChannel = getTracingChannel('graphql:validate'); + +describe('validate diagnostics channel', () => { + it('emits start and end around a successful validate', async () => { + const document = parse('{ field }'); + + await expectEvents( + validateChannel, + () => validate(schema, document), + (result) => [ + { channel: 'start', context: { schema, document } }, + { channel: 'end', context: { schema, document, result } }, + ], + ); + }); + + it('emits start and end for a document with validation errors', async () => { + const document = parse('{ missingField }'); + + await expectEvents( + validateChannel, + () => validate(schema, document), + (result) => [ + { channel: 'start', context: { schema, document } }, + { channel: 'end', context: { schema, document, result } }, + ], + ); + }); + + it('emits start, error, and end when validate throws on an invalid schema', async () => { + const context = { + schema: {} as GraphQLSchema, + document: parse('{ field }'), + }; + + await expectEvents( + validateChannel, + () => expectToThrow(() => validate(context.schema, context.document)), + (error) => [ + { + channel: 'start', + context, + }, + { + channel: 'error', + context: { + ...context, + error, + }, + }, + { + channel: 'end', + context: { ...context, error }, + }, + ], + ); + }); + + it('does not call tracing methods when no subscribers are attached', async () => { + const errors = await expectNoTracingActivity(validateChannel, () => + validate(schema, parse('{ field }')), + ); + expect(errors).to.deep.equal([]); + }); +}); diff --git a/src/validation/validate.ts b/src/validation/validate.ts index 69c3725292..30a7ff12fa 100644 --- a/src/validation/validate.ts +++ b/src/validation/validate.ts @@ -12,6 +12,8 @@ import { assertValidSchema } from '../type/validate.ts'; import { TypeInfo, visitWithTypeInfo } from '../utilities/TypeInfo.ts'; +import { shouldTrace, validateChannel } from '../diagnostics.ts'; + import { specifiedRules, specifiedSDLRules } from './specifiedRules.ts'; import type { SDLValidationRule, ValidationRule } from './ValidationContext.ts'; import { @@ -60,6 +62,20 @@ export function validate( documentAST: DocumentNode, rules: ReadonlyArray = specifiedRules, options?: ValidationOptions, +): ReadonlyArray { + return shouldTrace(validateChannel) + ? validateChannel.traceSync( + () => validateImpl(schema, documentAST, rules, options), + { schema, document: documentAST }, + ) + : validateImpl(schema, documentAST, rules, options); +} + +function validateImpl( + schema: GraphQLSchema, + documentAST: DocumentNode, + rules: ReadonlyArray, + options: ValidationOptions | undefined, ): ReadonlyArray { const maxErrors = options?.maxErrors ?? 100; const hideSuggestions = options?.hideSuggestions ?? false; @@ -82,8 +98,8 @@ export function validate( hideSuggestions, ); - // This uses a specialized visitor which runs multiple visitors in parallel, - // while maintaining the visitor skip and break API. + // This uses a specialized visitor which runs multiple visitors in + // parallel, while maintaining the visitor skip and break API. const visitor = visitInParallel(rules.map((rule) => rule(context))); // Visit the whole document with each instance of all provided rules.