diff --git a/integrationTests/diagnostics/package.json b/integrationTests/diagnostics/package.json new file mode 100644 index 0000000000..0face40966 --- /dev/null +++ b/integrationTests/diagnostics/package.json @@ -0,0 +1,14 @@ +{ + "description": "graphql-js tracing channels should publish on node:diagnostics_channel", + "private": true, + "type": "module", + "engines": { + "node": ">=22.0.0" + }, + "scripts": { + "test": "node test.js" + }, + "dependencies": { + "graphql": "file:../graphql.tgz" + } +} diff --git a/integrationTests/diagnostics/test.js b/integrationTests/diagnostics/test.js new file mode 100644 index 0000000000..93ed499b7a --- /dev/null +++ b/integrationTests/diagnostics/test.js @@ -0,0 +1,297 @@ +// 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, + enableDiagnosticsChannel, + execute, + parse, + subscribe, + validate, +} from 'graphql'; + +enableDiagnosticsChannel(dc); + +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', + operationType: msg.operationType, + operationName: msg.operationName, + document: msg.document, + schema: msg.schema, + }), + 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); + } +} + +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', + operationType: msg.operationType, + operationName: msg.operationName, + }), + 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, + fieldPath: msg.fieldPath, + isTrivialResolver: msg.isTrivialResolver, + }), + 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.isTrivialResolver, 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 ctx object. + const als = new AsyncLocalStorage(); + const channel = dc.tracingChannel('graphql:execute'); + channel.start.bindStore(als, (ctx) => ({ operationName: ctx.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(); + 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 1eb240d5d5..0e584726b0 100644 --- a/resources/integration-test.ts +++ b/resources/integration-test.ts @@ -55,6 +55,9 @@ describe('Integration Tests', () => { testOnNodeProject('node'); testOnNodeProject('webpack'); + // Tracing channel tests + testOnNodeProject('diagnostics'); + // Conditional export tests testOnNodeProject('conditions'); diff --git a/src/__testUtils__/fakeDiagnosticsChannel.ts b/src/__testUtils__/fakeDiagnosticsChannel.ts new file mode 100644 index 0000000000..6d99986214 --- /dev/null +++ b/src/__testUtils__/fakeDiagnosticsChannel.ts @@ -0,0 +1,164 @@ +import type { + MinimalChannel, + MinimalDiagnosticsChannel, + MinimalTracingChannel, +} from '../diagnostics.js'; + +export type Listener = (message: unknown) => void; + +/** + * In-memory `MinimalChannel` implementation used by the unit tests. Tracks + * subscribers and replays Node's `runStores` semantics by simply invoking + * `fn`. + */ +export class FakeChannel implements MinimalChannel { + listeners: Array = []; + + /* c8 ignore next 3 */ + get [Symbol.toStringTag]() { + return 'FakeChannel'; + } + + get hasSubscribers(): boolean { + return this.listeners.length > 0; + } + + publish(message: unknown): void { + for (const l of this.listeners) { + l(message); + } + } + + runStores( + ctx: ContextType, + fn: (this: ContextType, ...args: Array) => T, + thisArg?: unknown, + ...args: Array + ): T { + // Node's Channel.runStores publishes the context on the channel before + // invoking fn. Mirror that here so traceSync / tracePromise fake exactly + // matches real Node's start / end event counts. + this.publish(ctx); + return fn.apply(thisArg as ContextType, args); + } + + subscribe(listener: Listener): void { + this.listeners.push(listener); + } + + unsubscribe(listener: Listener): void { + const idx = this.listeners.indexOf(listener); + if (idx >= 0) { + this.listeners.splice(idx, 1); + } + } +} + +/** + * Structurally-faithful `MinimalTracingChannel` implementation mirroring + * Node's `TracingChannel.traceSync` lifecycle. + */ +export class FakeTracingChannel implements MinimalTracingChannel { + start: FakeChannel = new FakeChannel(); + end: FakeChannel = new FakeChannel(); + asyncStart: FakeChannel = new FakeChannel(); + asyncEnd: FakeChannel = new FakeChannel(); + error: FakeChannel = new FakeChannel(); + + /* c8 ignore next 3 */ + get [Symbol.toStringTag]() { + return 'FakeTracingChannel'; + } + + get hasSubscribers(): boolean { + return ( + this.start.hasSubscribers || + this.end.hasSubscribers || + this.asyncStart.hasSubscribers || + this.asyncEnd.hasSubscribers || + this.error.hasSubscribers + ); + } + + traceSync( + fn: (...args: Array) => T, + ctx: object, + thisArg?: unknown, + ...args: Array + ): T { + return this.start.runStores(ctx, () => { + let result: T; + try { + result = fn.apply(thisArg as object, args); + } catch (err) { + (ctx as { error: unknown }).error = err; + this.error.publish(ctx); + this.end.publish(ctx); + throw err; + } + // Node's real traceSync sets `ctx.result` before publishing `end`, so + // subscribers can inspect `ctx.result` inside their `end` handler. + (ctx as { result: unknown }).result = result; + this.end.publish(ctx); + return result; + }); + } +} + +export class FakeDc implements MinimalDiagnosticsChannel { + private cache = new Map(); + + /* c8 ignore next 3 */ + get [Symbol.toStringTag]() { + return 'FakeDc'; + } + + tracingChannel(name: string): FakeTracingChannel { + let existing = this.cache.get(name); + if (existing === undefined) { + existing = new FakeTracingChannel(); + this.cache.set(name, existing); + } + return existing; + } +} + +export interface CollectedEvent { + kind: 'start' | 'end' | 'asyncStart' | 'asyncEnd' | 'error'; + ctx: { [key: string]: unknown }; +} + +/** + * Attach listeners to every sub-channel on a FakeTracingChannel and return + * the captured event buffer plus an unsubscribe hook. + */ +export function collectEvents(channel: FakeTracingChannel): { + events: Array; + unsubscribe: () => void; +} { + const events: Array = []; + const make = + (kind: CollectedEvent['kind']): Listener => + (m) => + events.push({ kind, ctx: m as { [key: string]: unknown } }); + const startL = make('start'); + const endL = make('end'); + const asyncStartL = make('asyncStart'); + const asyncEndL = make('asyncEnd'); + const errorL = make('error'); + channel.start.subscribe(startL); + channel.end.subscribe(endL); + channel.asyncStart.subscribe(asyncStartL); + channel.asyncEnd.subscribe(asyncEndL); + channel.error.subscribe(errorL); + return { + events, + unsubscribe() { + channel.start.unsubscribe(startL); + channel.end.unsubscribe(endL); + channel.asyncStart.unsubscribe(asyncStartL); + channel.asyncEnd.unsubscribe(asyncEndL); + channel.error.unsubscribe(errorL); + }, + }; +} diff --git a/src/__tests__/diagnostics-test.ts b/src/__tests__/diagnostics-test.ts new file mode 100644 index 0000000000..06a0c5ff3a --- /dev/null +++ b/src/__tests__/diagnostics-test.ts @@ -0,0 +1,108 @@ +import { expect } from 'chai'; +import { describe, it } from 'mocha'; + +import { invariant } from '../jsutils/invariant.js'; + +import type { + MinimalDiagnosticsChannel, + MinimalTracingChannel, +} from '../diagnostics.js'; +import { enableDiagnosticsChannel, getChannels } from '../diagnostics.js'; + +function fakeTracingChannel(name: string): MinimalTracingChannel { + const noop: MinimalTracingChannel['start'] = { + hasSubscribers: false, + publish: () => { + /* noop */ + }, + runStores: ( + _ctx: unknown, + fn: (this: unknown, ...args: Array) => T, + ): T => fn(), + }; + const channel: MinimalTracingChannel & { _name: string } = { + _name: name, + hasSubscribers: false, + start: noop, + end: noop, + asyncStart: noop, + asyncEnd: noop, + error: noop, + traceSync: (fn: (...args: Array) => T): T => fn(), + }; + return channel; +} + +function fakeDc(): MinimalDiagnosticsChannel & { + created: Array; +} { + const created: Array = []; + const cache = new Map(); + return { + created, + tracingChannel(name: string) { + let existing = cache.get(name); + if (existing === undefined) { + created.push(name); + existing = fakeTracingChannel(name); + cache.set(name, existing); + } + return existing; + }, + }; +} + +describe('diagnostics', () => { + it('registers the five graphql tracing channels', () => { + const dc = fakeDc(); + enableDiagnosticsChannel(dc); + + expect(dc.created).to.deep.equal([ + 'graphql:execute', + 'graphql:parse', + 'graphql:validate', + 'graphql:resolve', + 'graphql:subscribe', + ]); + + const channels = getChannels(); + invariant(channels !== undefined); + expect(channels.execute).to.not.equal(undefined); + expect(channels.parse).to.not.equal(undefined); + expect(channels.validate).to.not.equal(undefined); + expect(channels.resolve).to.not.equal(undefined); + expect(channels.subscribe).to.not.equal(undefined); + }); + + it('re-registration with the same module preserves channel identity', () => { + const dc = fakeDc(); + enableDiagnosticsChannel(dc); + const first = getChannels(); + invariant(first !== undefined); + + enableDiagnosticsChannel(dc); + const second = getChannels(); + invariant(second !== undefined); + + expect(second.execute).to.equal(first.execute); + expect(second.parse).to.equal(first.parse); + expect(second.validate).to.equal(first.validate); + expect(second.resolve).to.equal(first.resolve); + expect(second.subscribe).to.equal(first.subscribe); + }); + + it('re-registration with a different module replaces stored references', () => { + const dc1 = fakeDc(); + const dc2 = fakeDc(); + + enableDiagnosticsChannel(dc1); + const first = getChannels(); + invariant(first !== undefined); + + enableDiagnosticsChannel(dc2); + const second = getChannels(); + invariant(second !== undefined); + + expect(second.execute).to.not.equal(first.execute); + }); +}); diff --git a/src/diagnostics.ts b/src/diagnostics.ts new file mode 100644 index 0000000000..52d65688d3 --- /dev/null +++ b/src/diagnostics.ts @@ -0,0 +1,217 @@ +/** + * TracingChannel integration. + * + * graphql-js exposes a set of named tracing channels that APM tools can + * subscribe to in order to observe parse, validate, execute, subscribe, and + * resolver lifecycle events. To preserve the isomorphic invariant of the + * core (no runtime-specific imports in `src/`), graphql-js does not import + * `node:diagnostics_channel` itself. Instead, APMs (or runtime-specific + * adapters) hand in a module satisfying `MinimalDiagnosticsChannel` via + * `enableDiagnosticsChannel`. + * + * Channel names are owned by graphql-js so multiple APMs converge on the + * same `TracingChannel` instances and all subscribers coexist. + */ + +import { isPromise } from './jsutils/isPromise.js'; + +/** + * Structural subset of `DiagnosticsChannel` sufficient for publishing and + * subscriber gating. `node:diagnostics_channel`'s `Channel` satisfies this. + */ +export interface MinimalChannel { + readonly hasSubscribers: boolean; + publish: (message: unknown) => 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. + */ +export interface MinimalTracingChannel { + readonly hasSubscribers: boolean; + readonly start: MinimalChannel; + readonly end: MinimalChannel; + readonly asyncStart: MinimalChannel; + readonly asyncEnd: MinimalChannel; + readonly error: MinimalChannel; + + traceSync: ( + fn: (...args: Array) => T, + ctx: object, + thisArg?: unknown, + ...args: Array + ) => T; +} + +/** + * Structural subset of `node:diagnostics_channel` covering just what + * graphql-js needs at registration time. + */ +export interface MinimalDiagnosticsChannel { + tracingChannel: (name: string) => MinimalTracingChannel; +} + +/** + * 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; + parse: MinimalTracingChannel; + validate: MinimalTracingChannel; + resolve: MinimalTracingChannel; + subscribe: MinimalTracingChannel; +} + +let channels: GraphQLChannels | undefined; + +/** + * Internal accessor used at emission sites. Returns `undefined` when no + * `diagnostics_channel` module has been registered, allowing emission sites + * to short-circuit on a single property access. + * + * @internal + */ +export function getChannels(): GraphQLChannels | undefined { + return channels; +} + +/** + * Register a `node:diagnostics_channel`-compatible module with graphql-js. + * + * After calling this, graphql-js will publish lifecycle events on the + * following tracing channels whenever subscribers are present: + * + * - `graphql:parse` + * - `graphql:validate` + * - `graphql:execute` + * - `graphql:subscribe` + * - `graphql:resolve` + * + * Calling this repeatedly is safe: subsequent calls replace the stored + * channel references, but since `tracingChannel(name)` is cached by name, + * the channel identities remain stable across registrations from the same + * underlying module. + * + * @example + * ```ts + * import dc from 'node:diagnostics_channel'; + * import { enableDiagnosticsChannel } from 'graphql'; + * + * enableDiagnosticsChannel(dc); + * ``` + */ +export function enableDiagnosticsChannel(dc: MinimalDiagnosticsChannel): void { + channels = { + execute: dc.tracingChannel('graphql:execute'), + parse: dc.tracingChannel('graphql:parse'), + validate: dc.tracingChannel('graphql:validate'), + resolve: dc.tracingChannel('graphql:resolve'), + subscribe: dc.tracingChannel('graphql:subscribe'), + }; +} + +/** + * Gate for emission sites. Returns `true` when the named channel exists and + * publishing should proceed. + * + * Uses `!== false` rather than a truthy check so runtimes which do not + * implement the aggregated `hasSubscribers` getter on `TracingChannel` still + * publish. Notably Node 18 (nodejs/node#54470), where the aggregated getter + * returns `undefined` while sub-channels behave correctly. + * + * @internal + */ +export function shouldTrace( + channel: MinimalTracingChannel | undefined, +): channel is MinimalTracingChannel { + // eslint-disable-next-line @typescript-eslint/no-unnecessary-boolean-literal-compare + return channel !== undefined && channel.hasSubscribers !== false; +} + +/** + * Publish a synchronous operation through the named graphql tracing channel, + * short-circuiting to `fn()` when the channel isn't registered or nothing is + * listening. + * + * @internal + */ +export function maybeTraceSync( + name: keyof GraphQLChannels, + ctxFactory: () => object, + fn: () => T, +): T { + const channel = getChannels()?.[name]; + if (!shouldTrace(channel)) { + return fn(); + } + return channel.traceSync(fn, ctxFactory()); +} + +/** + * Publish a mixed sync-or-promise operation through the named graphql tracing + * channel. + * + * @internal + */ +export function maybeTraceMixed( + name: keyof GraphQLChannels, + ctxFactory: () => object, + fn: () => T | Promise, +): T | Promise { + const channel = getChannels()?.[name]; + if (!shouldTrace(channel)) { + return fn(); + } + const ctx = ctxFactory() as { + error?: unknown; + result?: unknown; + }; + + return channel.start.runStores(ctx, () => { + let result: T | Promise; + try { + result = fn(); + } catch (err) { + ctx.error = err; + channel.error.publish(ctx); + channel.end.publish(ctx); + throw err; + } + + if (!isPromise(result)) { + ctx.result = result; + channel.end.publish(ctx); + return result; + } + + channel.end.publish(ctx); + channel.asyncStart.publish(ctx); + + return result + .then( + (value) => { + ctx.result = value; + return value; + }, + (err: unknown) => { + ctx.error = err; + channel.error.publish(ctx); + throw err; + }, + ) + .finally(() => { + channel.asyncEnd.publish(ctx); + }); + }); +} diff --git a/src/execution/Executor.ts b/src/execution/Executor.ts index bcee51fb1e..bf4a981f8e 100644 --- a/src/execution/Executor.ts +++ b/src/execution/Executor.ts @@ -44,6 +44,9 @@ import { } from '../type/definition.js'; import type { GraphQLSchema } from '../type/schema.js'; +import type { MinimalTracingChannel } from '../diagnostics.js'; +import { getChannels, maybeTraceMixed, shouldTrace } from '../diagnostics.js'; + import { withCancellation } from './cancellablePromise.js'; import type { DeferUsage, @@ -242,6 +245,12 @@ export class Executor< values: ReadonlyArray>, ) => Promise>; + // Resolved once per Executor so the per-field gate in `executeField` is a + // single member read + null check, not a `getChannels()?.resolve` walk + + // `hasSubscribers` read on every resolution. Undefined when diagnostics + // are off or nobody is listening at construction time. + _resolveChannel: MinimalTracingChannel | undefined; + constructor( validatedExecutionArgs: ValidatedExecutionArgs, sharedExecutionContext?: SharedExecutionContext, @@ -251,6 +260,11 @@ export class Executor< this.abortReason = defaultAbortReason; this.collectedErrors = new CollectedErrors(); + const resolveChannel = getChannels()?.resolve; + this._resolveChannel = shouldTrace(resolveChannel) + ? resolveChannel + : undefined; + if (sharedExecutionContext === undefined) { this.resolverAbortController = new AbortController(); this.sharedExecutionContext = createSharedExecutionContext( @@ -608,7 +622,13 @@ export class Executor< // The resolve function's optional third argument is a context value that // is provided to every resolve function within an execution. It is commonly // used to represent an authenticated user, or request-specific caches. - const result = resolveFn(source, args, contextValue, info); + const result = this._resolveChannel + ? maybeTraceMixed( + 'resolve', + () => buildResolveCtx(info, args, fieldDef.resolve === undefined), + () => resolveFn(source, args, contextValue, info), + ) + : resolveFn(source, args, contextValue, info); if (isPromise(result)) { return this.completePromisedValue( @@ -1395,3 +1415,29 @@ export class Executor< function toNodes(fieldDetailsList: FieldDetailsList): ReadonlyArray { return fieldDetailsList.map((fieldDetails) => fieldDetails.node); } + +/** + * 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 trivial resolvers + * often never read it. `args` is passed through by reference. + */ +function buildResolveCtx( + info: GraphQLResolveInfo, + args: { readonly [argument: string]: unknown }, + isTrivialResolver: boolean, +): object { + let cachedFieldPath: string | undefined; + return { + fieldName: info.fieldName, + parentType: info.parentType.name, + fieldType: String(info.returnType), + args, + isTrivialResolver, + get fieldPath() { + cachedFieldPath ??= pathToArray(info.path).join('.'); + return cachedFieldPath; + }, + }; +} diff --git a/src/execution/__tests__/execute-diagnostics-test.ts b/src/execution/__tests__/execute-diagnostics-test.ts new file mode 100644 index 0000000000..45fcbdee3c --- /dev/null +++ b/src/execution/__tests__/execute-diagnostics-test.ts @@ -0,0 +1,139 @@ +import { expect } from 'chai'; +import { afterEach, beforeEach, describe, it } from 'mocha'; + +import { + collectEvents, + FakeDc, +} from '../../__testUtils__/fakeDiagnosticsChannel.js'; + +import { parse } from '../../language/parser.js'; + +import { buildSchema } from '../../utilities/buildASTSchema.js'; + +import { enableDiagnosticsChannel } from '../../diagnostics.js'; + +import type { ExecutionArgs } from '../execute.js'; +import { + execute, + executeSubscriptionEvent, + executeSync, + validateExecutionArgs, +} from '../execute.js'; + +const schema = buildSchema(` + type Query { + sync: String + async: String + } +`); + +const rootValue = { + sync: () => 'hello', + async: () => Promise.resolve('hello-async'), +}; + +const fakeDc = new FakeDc(); +const executeChannel = fakeDc.tracingChannel('graphql:execute'); + +describe('execute diagnostics channel', () => { + let active: ReturnType | undefined; + + beforeEach(() => { + enableDiagnosticsChannel(fakeDc); + }); + + afterEach(() => { + active?.unsubscribe(); + active = undefined; + }); + + it('emits start and end around a synchronous execute', () => { + active = collectEvents(executeChannel); + + const document = parse('query Q { sync }'); + const result = execute({ schema, document, rootValue }); + + expect(result).to.deep.equal({ data: { sync: 'hello' } }); + expect(active.events.map((e) => e.kind)).to.deep.equal(['start', 'end']); + expect(active.events[0].ctx.operationType).to.equal('query'); + expect(active.events[0].ctx.operationName).to.equal('Q'); + expect(active.events[0].ctx.document).to.equal(document); + expect(active.events[0].ctx.schema).to.equal(schema); + }); + + it('emits start, end, and async lifecycle when execute returns a promise', async () => { + active = collectEvents(executeChannel); + + const document = parse('query { async }'); + const result = await execute({ schema, document, rootValue }); + + expect(result).to.deep.equal({ data: { async: 'hello-async' } }); + expect(active.events.map((e) => e.kind)).to.deep.equal([ + 'start', + 'end', + 'asyncStart', + 'asyncEnd', + ]); + }); + + it('emits once for executeSync via experimentalExecuteIncrementally', () => { + active = collectEvents(executeChannel); + + const document = parse('{ sync }'); + executeSync({ schema, document, rootValue }); + + expect(active.events.map((e) => e.kind)).to.deep.equal(['start', 'end']); + }); + + it('emits start, error, and end when execute throws synchronously', () => { + active = collectEvents(executeChannel); + + const schemaWithDefer = buildSchema(` + directive @defer on FIELD + type Query { sync: String } + `); + const document = parse('{ sync }'); + expect(() => + execute({ schema: schemaWithDefer, document, rootValue }), + ).to.throw(); + + expect(active.events.map((e) => e.kind)).to.deep.equal([ + 'start', + 'error', + 'end', + ]); + }); + + it('emits for each executeSubscriptionEvent call with resolved operation ctx', () => { + const args: ExecutionArgs = { + schema, + document: parse('query Q { sync }'), + rootValue, + }; + const validated = validateExecutionArgs(args); + if (!('schema' in validated)) { + throw new Error('unexpected validation failure'); + } + + active = collectEvents(executeChannel); + + // eslint-disable-next-line @typescript-eslint/no-floating-promises + executeSubscriptionEvent(validated); + // eslint-disable-next-line @typescript-eslint/no-floating-promises + executeSubscriptionEvent(validated); + + const starts = active.events.filter((e) => e.kind === 'start'); + expect(starts.length).to.equal(2); + for (const ev of starts) { + expect(ev.ctx.operationType).to.equal('query'); + expect(ev.ctx.operationName).to.equal('Q'); + expect(ev.ctx.schema).to.equal(schema); + } + }); + + it('does nothing when no subscribers are attached', () => { + const document = parse('{ sync }'); + const result = execute({ schema, document, rootValue }); + expect(result).to.deep.equal({ data: { sync: 'hello' } }); + }); +}); diff --git a/src/execution/__tests__/resolve-diagnostics-test.ts b/src/execution/__tests__/resolve-diagnostics-test.ts new file mode 100644 index 0000000000..1608bc4471 --- /dev/null +++ b/src/execution/__tests__/resolve-diagnostics-test.ts @@ -0,0 +1,198 @@ +import { expect } from 'chai'; +import { afterEach, beforeEach, describe, it } from 'mocha'; + +import { + collectEvents, + FakeDc, +} from '../../__testUtils__/fakeDiagnosticsChannel.js'; + +import { isPromise } from '../../jsutils/isPromise.js'; + +import { parse } from '../../language/parser.js'; + +import { GraphQLObjectType } from '../../type/definition.js'; +import { GraphQLString } from '../../type/scalars.js'; +import { GraphQLSchema } from '../../type/schema.js'; + +import { buildSchema } from '../../utilities/buildASTSchema.js'; + +import { enableDiagnosticsChannel } from '../../diagnostics.js'; + +import { execute } from '../execute.js'; + +const schema = buildSchema(` + type Query { + sync: String + async: String + fail: String + asyncFail: String + plain: String + nested: Nested + } + type Nested { + leaf: String + } +`); + +const rootValue = { + sync: () => 'hello', + async: () => Promise.resolve('hello-async'), + fail: () => { + throw new Error('boom'); + }, + asyncFail: () => Promise.reject(new Error('async-boom')), + // no `plain` resolver, default property-access is used. + plain: 'plain-value', + nested: { leaf: 'leaf-value' }, +}; + +const fakeDc = new FakeDc(); +const resolveChannel = fakeDc.tracingChannel('graphql:resolve'); + +describe('resolve diagnostics channel', () => { + let active: ReturnType | undefined; + + beforeEach(() => { + enableDiagnosticsChannel(fakeDc); + }); + + afterEach(() => { + active?.unsubscribe(); + active = undefined; + }); + + it('emits start and end around a synchronous resolver', () => { + active = collectEvents(resolveChannel); + + const result = execute({ schema, document: parse('{ sync }'), rootValue }); + if (isPromise(result)) { + throw new Error('expected sync'); + } + + const starts = active.events.filter((e) => e.kind === 'start'); + expect(starts.length).to.equal(1); + expect(starts[0].ctx.fieldName).to.equal('sync'); + expect(starts[0].ctx.parentType).to.equal('Query'); + expect(starts[0].ctx.fieldType).to.equal('String'); + expect(starts[0].ctx.fieldPath).to.equal('sync'); + + const kinds = active.events.map((e) => e.kind); + expect(kinds).to.deep.equal(['start', 'end']); + }); + + it('emits the full async lifecycle when a resolver returns a promise', async () => { + active = collectEvents(resolveChannel); + + const result = execute({ schema, document: parse('{ async }'), rootValue }); + await result; + + const kinds = active.events.map((e) => e.kind); + expect(kinds).to.deep.equal(['start', 'end', 'asyncStart', 'asyncEnd']); + }); + + it('emits start, error, end when a sync resolver throws', () => { + active = collectEvents(resolveChannel); + + // eslint-disable-next-line @typescript-eslint/no-floating-promises + execute({ schema, document: parse('{ fail }'), rootValue }); + + const kinds = active.events.map((e) => e.kind); + expect(kinds).to.deep.equal(['start', 'error', 'end']); + }); + + it('emits full async lifecycle with error when a resolver rejects', async () => { + active = collectEvents(resolveChannel); + + await execute({ + schema, + document: parse('{ asyncFail }'), + rootValue, + }); + + const kinds = active.events.map((e) => e.kind); + expect(kinds).to.deep.equal([ + 'start', + 'end', + 'asyncStart', + 'error', + 'asyncEnd', + ]); + const errorEvent = active.events.find((e) => e.kind === 'error'); + expect((errorEvent?.ctx as { error?: Error }).error?.message).to.equal( + 'async-boom', + ); + }); + + it('reports isTrivialResolver based on field.resolve presence', () => { + const trivialSchema = new GraphQLSchema({ + query: new GraphQLObjectType({ + name: 'Query', + fields: { + trivial: { type: GraphQLString }, + custom: { + type: GraphQLString, + resolve: () => 'explicit', + }, + }, + }), + }); + + active = collectEvents(resolveChannel); + + // eslint-disable-next-line @typescript-eslint/no-floating-promises + execute({ + schema: trivialSchema, + document: parse('{ trivial custom }'), + rootValue: { trivial: 'value' }, + }); + + const starts = active.events.filter((e) => e.kind === 'start'); + const byField = new Map( + starts.map((e) => [e.ctx.fieldName, e.ctx.isTrivialResolver]), + ); + expect(byField.get('trivial')).to.equal(true); + expect(byField.get('custom')).to.equal(false); + }); + + it('serializes fieldPath lazily, joining path keys with dots', () => { + active = collectEvents(resolveChannel); + + // eslint-disable-next-line @typescript-eslint/no-floating-promises + execute({ + schema, + document: parse('{ nested { leaf } }'), + rootValue, + }); + + const starts = active.events.filter((e) => e.kind === 'start'); + const paths = starts.map((e) => e.ctx.fieldPath); + expect(paths).to.deep.equal(['nested', 'nested.leaf']); + }); + + it('fires once per field, not per schema walk', () => { + active = collectEvents(resolveChannel); + + // eslint-disable-next-line @typescript-eslint/no-floating-promises + execute({ + schema, + document: parse('{ sync plain nested { leaf } }'), + rootValue, + }); + + const starts = active.events.filter((e) => e.kind === 'start'); + const endsSync = active.events.filter((e) => e.kind === 'end'); + expect(starts.length).to.equal(4); // sync, plain, nested, nested.leaf + expect(endsSync.length).to.equal(4); + }); + + it('does nothing when no subscribers are attached', () => { + const result = execute({ + schema, + document: parse('{ sync }'), + rootValue, + }); + if (isPromise(result)) { + throw new Error('expected sync'); + } + }); +}); diff --git a/src/execution/__tests__/subscribe-diagnostics-test.ts b/src/execution/__tests__/subscribe-diagnostics-test.ts new file mode 100644 index 0000000000..a1b1987ecb --- /dev/null +++ b/src/execution/__tests__/subscribe-diagnostics-test.ts @@ -0,0 +1,130 @@ +import { expect } from 'chai'; +import { afterEach, beforeEach, describe, it } from 'mocha'; + +import { + collectEvents, + FakeDc, +} from '../../__testUtils__/fakeDiagnosticsChannel.js'; + +import { isPromise } from '../../jsutils/isPromise.js'; + +import { parse } from '../../language/parser.js'; + +import { GraphQLObjectType } from '../../type/definition.js'; +import { GraphQLString } from '../../type/scalars.js'; +import { GraphQLSchema } from '../../type/schema.js'; + +import { enableDiagnosticsChannel } from '../../diagnostics.js'; + +import { subscribe } from '../execute.js'; + +function buildSubscriptionSchema( + subscribeFn: () => AsyncIterable<{ tick: string }>, +): GraphQLSchema { + return new GraphQLSchema({ + query: new GraphQLObjectType({ + name: 'Query', + fields: { dummy: { type: GraphQLString } }, + }), + subscription: new GraphQLObjectType({ + name: 'Subscription', + fields: { + tick: { + type: GraphQLString, + subscribe: subscribeFn, + }, + }, + }), + }); +} + +async function* twoTicks(): AsyncIterable<{ tick: string }> { + await Promise.resolve(); + yield { tick: 'one' }; + yield { tick: 'two' }; +} + +const fakeDc = new FakeDc(); +const subscribeChannel = fakeDc.tracingChannel('graphql:subscribe'); + +describe('subscribe diagnostics channel', () => { + let active: ReturnType | undefined; + + beforeEach(() => { + enableDiagnosticsChannel(fakeDc); + }); + + afterEach(() => { + active?.unsubscribe(); + active = undefined; + }); + + it('emits start and end for a synchronous subscription setup', async () => { + active = collectEvents(subscribeChannel); + + const schema = buildSubscriptionSchema(twoTicks); + const document = parse('subscription S { tick }'); + + const result = subscribe({ schema, document }); + const resolved = isPromise(result) ? await result : result; + if (!(Symbol.asyncIterator in resolved)) { + throw new Error('Expected an async iterator'); + } + await resolved.return?.(); + + expect(active.events.map((e) => e.kind)).to.deep.equal(['start', 'end']); + expect(active.events[0].ctx.operationType).to.equal('subscription'); + expect(active.events[0].ctx.operationName).to.equal('S'); + expect(active.events[0].ctx.document).to.equal(document); + expect(active.events[0].ctx.schema).to.equal(schema); + }); + + it('emits the full async lifecycle when subscribe resolver returns a promise', async () => { + active = collectEvents(subscribeChannel); + + const asyncResolver = (): Promise> => + Promise.resolve(twoTicks()); + const schema = buildSubscriptionSchema( + asyncResolver as unknown as () => AsyncIterable<{ tick: string }>, + ); + const document = parse('subscription { tick }'); + + const result = subscribe({ schema, document }); + const resolved = isPromise(result) ? await result : result; + if (!(Symbol.asyncIterator in resolved)) { + throw new Error('Expected an async iterator'); + } + await resolved.return?.(); + + expect(active.events.map((e) => e.kind)).to.deep.equal([ + 'start', + 'end', + 'asyncStart', + 'asyncEnd', + ]); + }); + + it('emits only start and end for a synchronous validation failure', () => { + active = collectEvents(subscribeChannel); + + const schema = buildSubscriptionSchema(twoTicks); + // Invalid: no operation. + const document = parse('fragment F on Subscription { tick }'); + + // eslint-disable-next-line @typescript-eslint/no-floating-promises + subscribe({ schema, document }); + + expect(active.events.map((e) => e.kind)).to.deep.equal(['start', 'end']); + }); + + it('does nothing when no subscribers are attached', async () => { + const schema = buildSubscriptionSchema(twoTicks); + const document = parse('subscription { tick }'); + + const result = subscribe({ schema, document }); + const resolved = isPromise(result) ? await result : result; + if (Symbol.asyncIterator in resolved) { + await resolved.return?.(); + } + }); +}); diff --git a/src/execution/execute.ts b/src/execution/execute.ts index 35f50f3e30..73c2d30e37 100644 --- a/src/execution/execute.ts +++ b/src/execution/execute.ts @@ -32,6 +32,10 @@ import type { import { assertValidSchema } from '../type/index.js'; import type { GraphQLSchema } from '../type/schema.js'; +import { getOperationAST } from '../utilities/getOperationAST.js'; + +import { maybeTraceMixed } from '../diagnostics.js'; + import { cancellablePromise } from './cancellablePromise.js'; import type { FieldDetailsList, FragmentDetails } from './collectFields.js'; import { collectFields } from './collectFields.js'; @@ -49,6 +53,53 @@ import { getArgumentValues, getVariableValues } from './values.js'; const UNEXPECTED_EXPERIMENTAL_DIRECTIVES = 'The provided schema unexpectedly contains experimental directives (@defer or @stream). These directives may only be utilized if experimental execution features are explicitly enabled.'; +/** + * 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 buildExecuteCtxFromArgs(args: ExecutionArgs): () => object { + return () => { + let operation: OperationDefinitionNode | null | undefined; + const resolveOperation = (): OperationDefinitionNode | null | undefined => { + if (operation === undefined) { + operation = getOperationAST(args.document, args.operationName); + } + return operation; + }; + return { + document: args.document, + schema: args.schema, + variableValues: args.variableValues, + get operationName() { + return args.operationName ?? resolveOperation()?.name?.value; + }, + get operationType() { + return resolveOperation()?.operation; + }, + }; + }; +} + +/** + * Build a graphql:execute channel context from ValidatedExecutionArgs. + * Used by executeSubscriptionEvent, where 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:subscribe context. + */ +function buildExecuteCtxFromValidatedArgs( + args: ValidatedExecutionArgs, +): () => object { + return () => ({ + operation: args.operation, + schema: args.schema, + variableValues: args.variableValues, + operationName: args.operation.name?.value, + operationType: args.operation.operation, + }); +} + /** * Implements the "Executing requests" section of the GraphQL specification. * @@ -66,18 +117,23 @@ const UNEXPECTED_EXPERIMENTAL_DIRECTIVES = * delivery. */ export function execute(args: ExecutionArgs): PromiseOrValue { - if (args.schema.getDirective('defer') || args.schema.getDirective('stream')) { - throw new Error(UNEXPECTED_EXPERIMENTAL_DIRECTIVES); - } + return maybeTraceMixed('execute', buildExecuteCtxFromArgs(args), () => { + if ( + args.schema.getDirective('defer') || + args.schema.getDirective('stream') + ) { + throw new Error(UNEXPECTED_EXPERIMENTAL_DIRECTIVES); + } - const validatedExecutionArgs = validateExecutionArgs(args); + const validatedExecutionArgs = validateExecutionArgs(args); - // Return early errors if execution context failed. - if (!('schema' in validatedExecutionArgs)) { - return { errors: validatedExecutionArgs }; - } + // Return early errors if execution context failed. + if (!('schema' in validatedExecutionArgs)) { + return { errors: validatedExecutionArgs }; + } - return executeQueryOrMutationOrSubscriptionEvent(validatedExecutionArgs); + return executeQueryOrMutationOrSubscriptionEvent(validatedExecutionArgs); + }); } /** @@ -95,35 +151,39 @@ 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); - - // Return early errors if execution context failed. - if (!('schema' in validatedExecutionArgs)) { - return { errors: validatedExecutionArgs }; - } + return maybeTraceMixed('execute', buildExecuteCtxFromArgs(args), () => { + // 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 }; + } - return experimentalExecuteQueryOrMutationOrSubscriptionEvent( - validatedExecutionArgs, - ); + return experimentalExecuteQueryOrMutationOrSubscriptionEvent( + validatedExecutionArgs, + ); + }); } 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); - - // Return early errors if execution context failed. - if (!('schema' in validatedExecutionArgs)) { - return { errors: validatedExecutionArgs }; - } + return maybeTraceMixed('execute', buildExecuteCtxFromArgs(args), () => { + // 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 }; + } - return executeQueryOrMutationOrSubscriptionEventIgnoringIncremental( - validatedExecutionArgs, - ); + return executeQueryOrMutationOrSubscriptionEventIgnoringIncremental( + validatedExecutionArgs, + ); + }); } /** @@ -184,7 +244,11 @@ export function executeSync(args: ExecutionArgs): ExecutionResult { export function executeSubscriptionEvent( validatedExecutionArgs: ValidatedExecutionArgs, ): PromiseOrValue { - return executeQueryOrMutationOrSubscriptionEvent(validatedExecutionArgs); + return maybeTraceMixed( + 'execute', + buildExecuteCtxFromValidatedArgs(validatedExecutionArgs), + () => executeQueryOrMutationOrSubscriptionEvent(validatedExecutionArgs), + ); } /** @@ -218,24 +282,26 @@ 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. - const validatedExecutionArgs = validateExecutionArgs(args); - - // Return early errors if execution context failed. - if (!('schema' in validatedExecutionArgs)) { - return { errors: validatedExecutionArgs }; - } + return maybeTraceMixed('subscribe', buildExecuteCtxFromArgs(args), () => { + // 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 }; + } - const resultOrStream = createSourceEventStreamImpl(validatedExecutionArgs); + const resultOrStream = createSourceEventStreamImpl(validatedExecutionArgs); - if (isPromise(resultOrStream)) { - return resultOrStream.then((resolvedResultOrStream) => - mapSourceToResponse(validatedExecutionArgs, resolvedResultOrStream), - ); - } + if (isPromise(resultOrStream)) { + return resultOrStream.then((resolvedResultOrStream) => + mapSourceToResponse(validatedExecutionArgs, resolvedResultOrStream), + ); + } - return mapSourceToResponse(validatedExecutionArgs, resultOrStream); + return mapSourceToResponse(validatedExecutionArgs, resultOrStream); + }); } /** diff --git a/src/index.ts b/src/index.ts index f9d95650fb..3b4ee8489f 100644 --- a/src/index.ts +++ b/src/index.ts @@ -32,6 +32,17 @@ export { version, versionInfo } from './version.js'; // Enable development mode for additional checks. export { enableDevMode, isDevModeEnabled } from './devMode.js'; +// Register a `node:diagnostics_channel`-compatible module to enable +// tracing channel emission from parse, validate, execute, subscribe, +// and resolver lifecycle events. +export { enableDiagnosticsChannel } from './diagnostics.js'; +export type { + MinimalChannel, + MinimalTracingChannel, + MinimalDiagnosticsChannel, + GraphQLChannels, +} from './diagnostics.js'; + // The primary entry point into fulfilling a GraphQL request. export type { GraphQLArgs } from './graphql.js'; export { graphql, graphqlSync } from './graphql.js'; diff --git a/src/language/__tests__/parser-diagnostics-test.ts b/src/language/__tests__/parser-diagnostics-test.ts new file mode 100644 index 0000000000..a970a73508 --- /dev/null +++ b/src/language/__tests__/parser-diagnostics-test.ts @@ -0,0 +1,53 @@ +import { expect } from 'chai'; +import { afterEach, beforeEach, describe, it } from 'mocha'; + +import { + collectEvents, + FakeDc, +} from '../../__testUtils__/fakeDiagnosticsChannel.js'; + +import { enableDiagnosticsChannel } from '../../diagnostics.js'; + +import { parse } from '../parser.js'; + +const fakeDc = new FakeDc(); +const parseChannel = fakeDc.tracingChannel('graphql:parse'); + +describe('parse diagnostics channel', () => { + let active: ReturnType | undefined; + + beforeEach(() => { + enableDiagnosticsChannel(fakeDc); + }); + + afterEach(() => { + active?.unsubscribe(); + active = undefined; + }); + + it('emits start and end around a successful parse', () => { + active = collectEvents(parseChannel); + + const doc = parse('{ field }'); + + expect(doc.kind).to.equal('Document'); + expect(active.events.map((e) => e.kind)).to.deep.equal(['start', 'end']); + expect(active.events[0].ctx.source).to.equal('{ field }'); + expect(active.events[1].ctx.source).to.equal('{ field }'); + }); + + it('emits start, error, and end when the parser throws', () => { + active = collectEvents(parseChannel); + + expect(() => parse('{ ')).to.throw(); + + const kinds = active.events.map((e) => e.kind); + expect(kinds).to.deep.equal(['start', 'error', 'end']); + expect(active.events[1].ctx.error).to.be.instanceOf(Error); + }); + + it('does nothing when no subscribers are attached', () => { + const doc = parse('{ field }'); + expect(doc.kind).to.equal('Document'); + }); +}); diff --git a/src/language/parser.ts b/src/language/parser.ts index d9e6dd8ba2..ba62a9ccb0 100644 --- a/src/language/parser.ts +++ b/src/language/parser.ts @@ -3,6 +3,8 @@ import type { Maybe } from '../jsutils/Maybe.js'; import type { GraphQLError } from '../error/GraphQLError.js'; import { syntaxError } from '../error/syntaxError.js'; +import { maybeTraceSync } from '../diagnostics.js'; + import type { ArgumentCoordinateNode, ArgumentNode, @@ -132,13 +134,19 @@ export function parse( source: string | Source, options?: ParseOptions, ): DocumentNode { - const parser = new Parser(source, options); - const document = parser.parseDocument(); - Object.defineProperty(document, 'tokenCount', { - enumerable: false, - value: parser.tokenCount, - }); - return document; + return maybeTraceSync( + 'parse', + () => ({ source }), + () => { + const parser = new Parser(source, options); + const document = parser.parseDocument(); + Object.defineProperty(document, 'tokenCount', { + enumerable: false, + value: parser.tokenCount, + }); + return document; + }, + ); } /** diff --git a/src/validation/__tests__/validate-diagnostics-test.ts b/src/validation/__tests__/validate-diagnostics-test.ts new file mode 100644 index 0000000000..28d1c40c3b --- /dev/null +++ b/src/validation/__tests__/validate-diagnostics-test.ts @@ -0,0 +1,78 @@ +import { expect } from 'chai'; +import { afterEach, beforeEach, describe, it } from 'mocha'; + +import { + collectEvents, + FakeDc, +} from '../../__testUtils__/fakeDiagnosticsChannel.js'; + +import { parse } from '../../language/parser.js'; + +import { buildSchema } from '../../utilities/buildASTSchema.js'; + +import { enableDiagnosticsChannel } from '../../diagnostics.js'; + +import { validate } from '../validate.js'; + +const schema = buildSchema(` + type Query { + field: String + } +`); + +const fakeDc = new FakeDc(); +const validateChannel = fakeDc.tracingChannel('graphql:validate'); + +describe('validate diagnostics channel', () => { + let active: ReturnType | undefined; + + beforeEach(() => { + enableDiagnosticsChannel(fakeDc); + }); + + afterEach(() => { + active?.unsubscribe(); + active = undefined; + }); + + it('emits start and end around a successful validate', () => { + active = collectEvents(validateChannel); + + const doc = parse('{ field }'); + const errors = validate(schema, doc); + + expect(errors).to.deep.equal([]); + expect(active.events.map((e) => e.kind)).to.deep.equal(['start', 'end']); + expect(active.events[0].ctx.schema).to.equal(schema); + expect(active.events[0].ctx.document).to.equal(doc); + }); + + it('emits start and end for a document with validation errors', () => { + active = collectEvents(validateChannel); + + const doc = parse('{ missingField }'); + const errors = validate(schema, doc); + + expect(errors).to.have.length.greaterThan(0); + // Validation errors are collected, not thrown, so we still see start/end. + expect(active.events.map((e) => e.kind)).to.deep.equal(['start', 'end']); + }); + + it('emits start, error, and end when validate throws on an invalid schema', () => { + active = collectEvents(validateChannel); + + expect(() => validate({} as typeof schema, parse('{ field }'))).to.throw(); + + expect(active.events.map((e) => e.kind)).to.deep.equal([ + 'start', + 'error', + 'end', + ]); + expect(active.events[1].ctx.error).to.be.instanceOf(Error); + }); + + it('does nothing when no subscribers are attached', () => { + const errors = validate(schema, parse('{ field }')); + expect(errors).to.deep.equal([]); + }); +}); diff --git a/src/validation/validate.ts b/src/validation/validate.ts index 544f8bc3aa..0c6a7499e6 100644 --- a/src/validation/validate.ts +++ b/src/validation/validate.ts @@ -12,6 +12,8 @@ import { assertValidSchema } from '../type/validate.js'; import { TypeInfo, visitWithTypeInfo } from '../utilities/TypeInfo.js'; +import { maybeTraceSync } from '../diagnostics.js'; + import { specifiedRules, specifiedSDLRules } from './specifiedRules.js'; import type { SDLValidationRule, ValidationRule } from './ValidationContext.js'; import { @@ -61,46 +63,52 @@ export function validate( rules: ReadonlyArray = specifiedRules, options?: ValidationOptions, ): ReadonlyArray { - const maxErrors = options?.maxErrors ?? 100; - const hideSuggestions = options?.hideSuggestions ?? false; - - // If the schema used for validation is invalid, throw an error. - assertValidSchema(schema); - - const errors: Array = []; - const typeInfo = new TypeInfo(schema); - const context = new ValidationContext( - schema, - documentAST, - typeInfo, - (error) => { - if (errors.length >= maxErrors) { - throw tooManyValidationErrorsError; + return maybeTraceSync( + 'validate', + () => ({ schema, document: documentAST }), + () => { + const maxErrors = options?.maxErrors ?? 100; + const hideSuggestions = options?.hideSuggestions ?? false; + + // If the schema used for validation is invalid, throw an error. + assertValidSchema(schema); + + const errors: Array = []; + const typeInfo = new TypeInfo(schema); + const context = new ValidationContext( + schema, + documentAST, + typeInfo, + (error) => { + if (errors.length >= maxErrors) { + throw tooManyValidationErrorsError; + } + errors.push(error); + }, + hideSuggestions, + ); + + // 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. + try { + visit( + documentAST, + visitWithTypeInfo(typeInfo, visitor), + QueryDocumentKeysToValidate, + ); + } catch (e: unknown) { + if (e === tooManyValidationErrorsError) { + errors.push(tooManyValidationErrorsError); + } else { + throw e; + } } - errors.push(error); + return errors; }, - hideSuggestions, ); - - // 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. - try { - visit( - documentAST, - visitWithTypeInfo(typeInfo, visitor), - QueryDocumentKeysToValidate, - ); - } catch (e: unknown) { - if (e === tooManyValidationErrorsError) { - errors.push(tooManyValidationErrorsError); - } else { - throw e; - } - } - return errors; } /**