From b8d270c2c567f4b024d7c2ef376fef987b816171 Mon Sep 17 00:00:00 2001 From: Arda TANRIKULU Date: Mon, 6 May 2024 18:13:34 +0300 Subject: [PATCH 1/6] More --- .changeset/ten-eggs-run.md | 22 ++++++ packages/delegate/src/debugging.ts | 35 +++++++++ packages/delegate/src/index.ts | 1 + packages/delegate/src/mergeFields.ts | 72 ++++++++++++++++++- .../stitch/src/createDelegationPlanBuilder.ts | 11 +++ 5 files changed, 140 insertions(+), 1 deletion(-) create mode 100644 .changeset/ten-eggs-run.md create mode 100644 packages/delegate/src/debugging.ts diff --git a/.changeset/ten-eggs-run.md b/.changeset/ten-eggs-run.md new file mode 100644 index 00000000000..44872df7b1c --- /dev/null +++ b/.changeset/ten-eggs-run.md @@ -0,0 +1,22 @@ +--- +"@graphql-tools/delegate": patch +"@graphql-tools/stitch": patch +--- + +Debugging the delegation plan; + +After you enable the environment variable, `EXPOSE_DELEGATION_PLAN`, you can see the delegation plan in the console. This can be useful for debugging and understanding how the delegation works. + +Also you can pass a different logger to it by using `logFnForContext` map from `@graphql-tools/delegate` package. + +```ts +import { logFnForContext } from '@graphql-tools/delegate'; +logFnForContext.set(MyGraphQLContext, console.log); +``` + +You can also add a `contextId` for that specific gateway request by using `contextIdMap` map from `@graphql-tools/delegate` package. + +```ts +import { contextIdMap } from '@graphql-tools/delegate'; +contextIdMap.set(MyGraphQLContext, 'my-request-id'); +``` diff --git a/packages/delegate/src/debugging.ts b/packages/delegate/src/debugging.ts new file mode 100644 index 00000000000..e4115530334 --- /dev/null +++ b/packages/delegate/src/debugging.ts @@ -0,0 +1,35 @@ +import { SelectionSetNode } from 'graphql'; +import { Subschema } from './Subschema.js'; + +export interface DelegationPlanInfo { + contextId?: string; + operationName?: string; + planId: string; + source?: string; + type?: string; + path: (string | number)[]; + fieldNodes?: string[]; + fragments: string[]; + stages: { + stageId: string; + delegations: { + target?: string; + selectionSet: string; + }[]; + }[]; +} + +export const delegationPlanIdMap = new WeakMap< + Map>, SelectionSetNode>[], + string +>(); +export const delegationStageIdMap = new WeakMap< + Map>, SelectionSetNode>, + string +>(); +export const logFnForContext = new WeakMap void>(); +export const delegationPlanInfosByContext = new WeakMap>(); +export const contextIdMap = new WeakMap(); +export function isDelegationDebugging() { + return globalThis.process?.env['EXPOSE_DELEGATION_PLAN']; +} diff --git a/packages/delegate/src/index.ts b/packages/delegate/src/index.ts index d7f981b5126..50a647f7d23 100644 --- a/packages/delegate/src/index.ts +++ b/packages/delegate/src/index.ts @@ -8,3 +8,4 @@ export * from './mergeFields.js'; export * from './resolveExternalValue.js'; export * from './subschemaConfig.js'; export * from './types.js'; +export * from './debugging.js'; diff --git a/packages/delegate/src/mergeFields.ts b/packages/delegate/src/mergeFields.ts index 7cacadcc89f..09b9a3b5c14 100644 --- a/packages/delegate/src/mergeFields.ts +++ b/packages/delegate/src/mergeFields.ts @@ -5,6 +5,7 @@ import { GraphQLResolveInfo, GraphQLSchema, locatedError, + print, responsePathAsArray, SelectionSetNode, } from 'graphql'; @@ -16,6 +17,15 @@ import { mergeDeep, relocatedError, } from '@graphql-tools/utils'; +import { + contextIdMap, + delegationPlanIdMap, + DelegationPlanInfo, + delegationPlanInfosByContext, + delegationStageIdMap, + isDelegationDebugging, + logFnForContext, +} from './debugging.js'; import { Subschema } from './Subschema.js'; import { FIELD_SUBSCHEMA_MAP_SYMBOL, @@ -83,9 +93,54 @@ export function mergeFields( : EMPTY_ARRAY, ); + let logFn: ((data: any) => void) | undefined; + if (isDelegationDebugging()) { + logFn = logFnForContext.get(context); + const delegationPlanInfo: DelegationPlanInfo = { + contextId: contextIdMap.get(context), + operationName: info.operation.name?.value, + planId: delegationPlanIdMap.get(delegationMaps)!, + source: sourceSubschema.name, + type: mergedTypeInfo.typeName, + path: responsePathAsArray(info.path), + fieldNodes: info.fieldNodes?.map(print), + fragments: Object.values(info.fragments || {}).map(fragmentNode => `${print(fragmentNode)}`), + stages: delegationMaps.map(delegationMap => ({ + stageId: delegationStageIdMap.get(delegationMap)!, + delegations: Array.from(delegationMap).map(([subschema, selectionSet]) => ({ + target: subschema.name, + selectionSet: print(selectionSet), + })), + })), + }; + let delegationPlanInfos = delegationPlanInfosByContext.get(context); + if (!delegationPlanInfos) { + delegationPlanInfos = new Set(); + delegationPlanInfosByContext.set(context, delegationPlanInfos); + } + delegationPlanInfos.add(delegationPlanInfo); + logFn?.({ + status: 'PLAN', + plan: delegationPlanInfo, + }); + } + const res$ = delegationMaps.reduce>((prev, delegationMap) => { function executeFn() { - return executeDelegationStage(mergedTypeInfo, delegationMap, object, context, info); + return executeDelegationStage( + mergedTypeInfo, + delegationMap, + object, + context, + info, + logFn + ? (data: any) => + logFn({ + stageId: delegationStageIdMap.get(delegationMap)!, + ...data, + }) + : undefined, + ); } if (isPromise(prev)) { return prev.then(executeFn); @@ -170,6 +225,7 @@ function executeDelegationStage( object: ExternalObject, context: any, info: GraphQLResolveInfo, + logFn?: (data: any) => void, ): MaybePromise { const combinedErrors = object[UNPATHED_ERRORS_SYMBOL]; @@ -178,9 +234,23 @@ function executeDelegationStage( const combinedFieldSubschemaMap = object[FIELD_SUBSCHEMA_MAP_SYMBOL]; const jobs: PromiseLike[] = []; + let delegationIndex = -1; for (const [subschema, selectionSet] of delegationMap) { const schema = subschema.transformedSchema || info.schema; const type = schema.getType(object.__typename) as GraphQLObjectType; + if (logFn) { + delegationIndex++; + logFn({ + status: 'EXECUTE_DELEGATION', + subschema: subschema.name, + typeName: type.name || mergedTypeInfo.typeName, + path, + selectionSet: print(selectionSet), + contextId: contextIdMap.get(context), + stageId: delegationStageIdMap.get(delegationMap)!, + delegationIndex, + }); + } const resolver = mergedTypeInfo.resolvers.get(subschema); if (resolver) { try { diff --git a/packages/stitch/src/createDelegationPlanBuilder.ts b/packages/stitch/src/createDelegationPlanBuilder.ts index 2c79a8ba8c1..21136b77af2 100644 --- a/packages/stitch/src/createDelegationPlanBuilder.ts +++ b/packages/stitch/src/createDelegationPlanBuilder.ts @@ -10,6 +10,9 @@ import { } from 'graphql'; import { DelegationPlanBuilder, + delegationPlanIdMap, + delegationStageIdMap, + isDelegationDebugging, MergedTypeInfo, StitchingInfo, Subschema, @@ -246,6 +249,10 @@ export function createDelegationPlanBuilder(mergedTypeInfo: MergedTypeInfo): Del ); let { delegationMap } = delegationStage; while (delegationMap.size) { + if (isDelegationDebugging()) { + const delegationStageId = Math.random().toString(36).slice(2); + delegationStageIdMap.set(delegationMap, delegationStageId); + } delegationMaps.push(delegationMap); const { proxiableSubschemas, nonProxiableSubschemas, unproxiableFieldNodes } = @@ -261,6 +268,10 @@ export function createDelegationPlanBuilder(mergedTypeInfo: MergedTypeInfo): Del ); delegationMap = delegationStage.delegationMap; } + if (isDelegationDebugging()) { + const delegationPlanId = Math.random().toString(36).slice(2); + delegationPlanIdMap.set(delegationMaps, delegationPlanId); + } return delegationMaps; }); } From b7759744c4a48363815cfc09d92a275b838f6bcb Mon Sep 17 00:00:00 2001 From: Arda TANRIKULU Date: Mon, 6 May 2024 18:14:25 +0300 Subject: [PATCH 2/6] More information --- .changeset/ten-eggs-run.md | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/.changeset/ten-eggs-run.md b/.changeset/ten-eggs-run.md index 44872df7b1c..e1da854584d 100644 --- a/.changeset/ten-eggs-run.md +++ b/.changeset/ten-eggs-run.md @@ -20,3 +20,11 @@ You can also add a `contextId` for that specific gateway request by using `conte import { contextIdMap } from '@graphql-tools/delegate'; contextIdMap.set(MyGraphQLContext, 'my-request-id'); ``` + +If you want to use those information instead of logging, you can get them by using the `context` object like below; + +```ts +import { delegationPlanInfosByContext } from '@graphql-tools/delegate'; +const delegationPlanInfos = delegationPlanInfosByContext.get(context); +``` + From d6f84a60d9ce16f45d3995e5af6c0f435ec1f82d Mon Sep 17 00:00:00 2001 From: Arda TANRIKULU Date: Mon, 6 May 2024 19:18:26 +0300 Subject: [PATCH 3/6] Better logging --- packages/delegate/src/debugging.ts | 30 +- packages/delegate/src/mergeFields.ts | 27 +- .../__snapshots__/debug-logging.test.ts.snap | 301 ++++++++++++++++++ .../federation/test/debug-logging.test.ts | 104 ++++++ 4 files changed, 442 insertions(+), 20 deletions(-) create mode 100644 packages/federation/test/__snapshots__/debug-logging.test.ts.snap create mode 100644 packages/federation/test/debug-logging.test.ts diff --git a/packages/delegate/src/debugging.ts b/packages/delegate/src/debugging.ts index e4115530334..89c5566aa60 100644 --- a/packages/delegate/src/debugging.ts +++ b/packages/delegate/src/debugging.ts @@ -1,5 +1,7 @@ -import { SelectionSetNode } from 'graphql'; +import { GraphQLResolveInfo, print, responsePathAsArray, SelectionSetNode } from 'graphql'; +import { memoize2of5, memoize5 } from '@graphql-tools/utils'; import { Subschema } from './Subschema.js'; +import { MergedTypeInfo } from './types.js'; export interface DelegationPlanInfo { contextId?: string; @@ -33,3 +35,29 @@ export const contextIdMap = new WeakMap(); export function isDelegationDebugging() { return globalThis.process?.env['EXPOSE_DELEGATION_PLAN']; } + +export const getDelegationInfo = memoize2of5(function getDelegationInfo( + context: any, + delegationMaps: Map, SelectionSetNode>[], + mergedTypeInfo: MergedTypeInfo, + sourceSubschema: Subschema, + info: GraphQLResolveInfo, +): DelegationPlanInfo { + return { + contextId: contextIdMap.get(context), + operationName: info.operation.name?.value, + planId: delegationPlanIdMap.get(delegationMaps)!, + source: sourceSubschema.name, + type: mergedTypeInfo.typeName, + path: responsePathAsArray(info.path).filter(key => typeof key === 'string'), + fieldNodes: info.fieldNodes?.map(print), + fragments: Object.values(info.fragments || {}).map(fragmentNode => `${print(fragmentNode)}`), + stages: delegationMaps.map(delegationMap => ({ + stageId: delegationStageIdMap.get(delegationMap)!, + delegations: Array.from(delegationMap).map(([subschema, selectionSet]) => ({ + target: subschema.name, + selectionSet: print(selectionSet), + })), + })), + }; +}); diff --git a/packages/delegate/src/mergeFields.ts b/packages/delegate/src/mergeFields.ts index 09b9a3b5c14..47a3034d100 100644 --- a/packages/delegate/src/mergeFields.ts +++ b/packages/delegate/src/mergeFields.ts @@ -19,10 +19,9 @@ import { } from '@graphql-tools/utils'; import { contextIdMap, - delegationPlanIdMap, - DelegationPlanInfo, delegationPlanInfosByContext, delegationStageIdMap, + getDelegationInfo, isDelegationDebugging, logFnForContext, } from './debugging.js'; @@ -96,28 +95,18 @@ export function mergeFields( let logFn: ((data: any) => void) | undefined; if (isDelegationDebugging()) { logFn = logFnForContext.get(context); - const delegationPlanInfo: DelegationPlanInfo = { - contextId: contextIdMap.get(context), - operationName: info.operation.name?.value, - planId: delegationPlanIdMap.get(delegationMaps)!, - source: sourceSubschema.name, - type: mergedTypeInfo.typeName, - path: responsePathAsArray(info.path), - fieldNodes: info.fieldNodes?.map(print), - fragments: Object.values(info.fragments || {}).map(fragmentNode => `${print(fragmentNode)}`), - stages: delegationMaps.map(delegationMap => ({ - stageId: delegationStageIdMap.get(delegationMap)!, - delegations: Array.from(delegationMap).map(([subschema, selectionSet]) => ({ - target: subschema.name, - selectionSet: print(selectionSet), - })), - })), - }; let delegationPlanInfos = delegationPlanInfosByContext.get(context); if (!delegationPlanInfos) { delegationPlanInfos = new Set(); delegationPlanInfosByContext.set(context, delegationPlanInfos); } + const delegationPlanInfo = getDelegationInfo( + context, + delegationMaps, + mergedTypeInfo, + sourceSubschema, + info, + ); delegationPlanInfos.add(delegationPlanInfo); logFn?.({ status: 'PLAN', diff --git a/packages/federation/test/__snapshots__/debug-logging.test.ts.snap b/packages/federation/test/__snapshots__/debug-logging.test.ts.snap new file mode 100644 index 00000000000..6c78361902b --- /dev/null +++ b/packages/federation/test/__snapshots__/debug-logging.test.ts.snap @@ -0,0 +1,301 @@ +// Jest Snapshot v1, https://goo.gl/fbAQLP + +exports[`Debug Logging should expose delegation plan correctly by context: delegationInfos 1`] = ` +Set { + { + "contextId": undefined, + "fieldNodes": [ + "users { + ...User + reviews { + ...Review + product { + ...Product + reviews { + ...Review + author { + ...User + reviews { + ...Review + product { + ...Product + } + } + } + } + } + } +}", + ], + "fragments": [ + "fragment User on User { + id + username + name +}", + "fragment Review on Review { + id + body +}", + "fragment Product on Product { + inStock + name + price + shippingEstimate + upc + weight +}", + ], + "operationName": "TestQuery", + "path": [ + "users", + ], + "planId": "4g00coussmu", + "source": "accounts", + "stages": [ + { + "delegations": [ + { + "selectionSet": "{ + reviews { + ...Review + product { + ...Product + reviews { + ...Review + author { + ...User + reviews { + ...Review + product { + ...Product + } + } + } + } + } + } +}", + "target": "reviews", + }, + ], + "stageId": "4fzyo82mvyq", + }, + ], + "type": "User", + }, + { + "contextId": undefined, + "fieldNodes": [ + "product { + ...Product + reviews { + ...Review + author { + ...User + reviews { + ...Review + product { + ...Product + } + } + } + } +}", + ], + "fragments": [ + "fragment User on User { + id + username + name +}", + "fragment Review on Review { + id + body +}", + "fragment Product on Product { + inStock + name + price + shippingEstimate + upc + weight +}", + ], + "operationName": "TestQuery", + "path": [ + "users", + "reviews", + "product", + ], + "planId": "4g05e37ain", + "source": "reviews", + "stages": [ + { + "delegations": [ + { + "selectionSet": "{ + inStock +}", + "target": "inventory", + }, + { + "selectionSet": "{ + name + price + price + weight + weight +}", + "target": "products", + }, + ], + "stageId": "4g0215mypav", + }, + { + "delegations": [ + { + "selectionSet": "{ + shippingEstimate +}", + "target": "inventory", + }, + ], + "stageId": "4g03pmf4lz", + }, + ], + "type": "Product", + }, + { + "contextId": undefined, + "fieldNodes": [ + "author { + ...User + reviews { + ...Review + product { + ...Product + } + } +}", + ], + "fragments": [ + "fragment User on User { + id + username + name +}", + "fragment Review on Review { + id + body +}", + "fragment Product on Product { + inStock + name + price + shippingEstimate + upc + weight +}", + ], + "operationName": "TestQuery", + "path": [ + "users", + "reviews", + "product", + "reviews", + "author", + ], + "planId": "4g08r0rmbz6", + "source": "reviews", + "stages": [ + { + "delegations": [ + { + "selectionSet": "{ + name +}", + "target": "accounts", + }, + ], + "stageId": "4g072jzgfb2", + }, + ], + "type": "User", + }, + { + "contextId": undefined, + "fieldNodes": [ + "product { + ...Product +}", + ], + "fragments": [ + "fragment User on User { + id + username + name +}", + "fragment Review on Review { + id + body +}", + "fragment Product on Product { + inStock + name + price + shippingEstimate + upc + weight +}", + ], + "operationName": "TestQuery", + "path": [ + "users", + "reviews", + "product", + "reviews", + "author", + "reviews", + "product", + ], + "planId": "4g0dsf441za", + "source": "reviews", + "stages": [ + { + "delegations": [ + { + "selectionSet": "{ + inStock +}", + "target": "inventory", + }, + { + "selectionSet": "{ + name + price + price + weight + weight +}", + "target": "products", + }, + ], + "stageId": "4g0afhjs8n8", + }, + { + "delegations": [ + { + "selectionSet": "{ + shippingEstimate +}", + "target": "inventory", + }, + ], + "stageId": "4g0c3yby5b9", + }, + ], + "type": "Product", + }, +} +`; diff --git a/packages/federation/test/debug-logging.test.ts b/packages/federation/test/debug-logging.test.ts new file mode 100644 index 00000000000..ee2310dbb5b --- /dev/null +++ b/packages/federation/test/debug-logging.test.ts @@ -0,0 +1,104 @@ +import { readFileSync, writeFileSync } from 'fs'; +import { join } from 'path'; +import { parse } from 'graphql'; +import { buildSubgraphSchema } from '@apollo/subgraph'; +import { createDefaultExecutor, delegationPlanInfosByContext } from '@graphql-tools/delegate'; +import { normalizedExecutor } from '@graphql-tools/executor'; +import { getStitchedSchemaFromSupergraphSdl } from '../src/supergraph'; +import * as accounts from './fixtures/gateway/accounts'; +import * as discount from './fixtures/gateway/discount'; +import * as inventory from './fixtures/gateway/inventory'; +import * as products from './fixtures/gateway/products'; +import * as reviews from './fixtures/gateway/reviews'; + +const services: Record = { + accounts, + inventory, + products, + reviews, + discount, +}; + +describe('Debug Logging', () => { + const existingFlag = process.env['EXPOSE_DELEGATION_PLAN']; + const existingMathRandom = Math.random; + beforeEach(() => { + process.env['EXPOSE_DELEGATION_PLAN'] = 'true'; + let counter = 0; + Math.random = () => 0.123456 + counter++ * 0.000001; + }); + afterEach(() => { + process.env['EXPOSE_DELEGATION_PLAN'] = existingFlag; + Math.random = existingMathRandom; + }); + const exampleQuery = /* GraphQL */ ` + fragment User on User { + id + username + name + } + + fragment Review on Review { + id + body + } + + fragment Product on Product { + inStock + name + price + shippingEstimate + upc + weight + } + + query TestQuery { + users { + ...User + reviews { + ...Review + product { + ...Product + reviews { + ...Review + author { + ...User + reviews { + ...Review + product { + ...Product + } + } + } + } + } + } + } + } + `; + const supergraphSdl = readFileSync( + join(__dirname, './fixtures/gateway/supergraph.graphql'), + 'utf8', + ); + const stitchedSchema = getStitchedSchemaFromSupergraphSdl({ + supergraphSdl, + onExecutor({ subgraphName }) { + const schema = buildSubgraphSchema({ + typeDefs: parse(services[subgraphName].typeDefs), + resolvers: services[subgraphName].resolvers, + }); + return createDefaultExecutor(schema); + }, + }); + it('should expose delegation plan correctly by context', async () => { + const contextValue = {}; + await normalizedExecutor({ + schema: stitchedSchema, + document: parse(exampleQuery), + contextValue, + }); + const delegationInfos = delegationPlanInfosByContext.get(contextValue); + expect(delegationInfos).toBeDefined(); + expect(delegationInfos).toMatchSnapshot('delegationInfos'); + }); +}); From 8b2547cdfa3dc0bc129b0f4f7ffc94a39609f5b5 Mon Sep 17 00:00:00 2001 From: Arda TANRIKULU Date: Mon, 6 May 2024 19:19:56 +0300 Subject: [PATCH 4/6] Fix --- packages/federation/test/debug-logging.test.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/federation/test/debug-logging.test.ts b/packages/federation/test/debug-logging.test.ts index ee2310dbb5b..aa85c3e163e 100644 --- a/packages/federation/test/debug-logging.test.ts +++ b/packages/federation/test/debug-logging.test.ts @@ -1,4 +1,4 @@ -import { readFileSync, writeFileSync } from 'fs'; +import { readFileSync } from 'fs'; import { join } from 'path'; import { parse } from 'graphql'; import { buildSubgraphSchema } from '@apollo/subgraph'; From 263febbe17fa52a402fdb06046db1cf1b59bdc52 Mon Sep 17 00:00:00 2001 From: Arda TANRIKULU Date: Mon, 6 May 2024 19:31:19 +0300 Subject: [PATCH 5/6] Fix build --- packages/delegate/src/debugging.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/delegate/src/debugging.ts b/packages/delegate/src/debugging.ts index 89c5566aa60..a1ba4ed7f40 100644 --- a/packages/delegate/src/debugging.ts +++ b/packages/delegate/src/debugging.ts @@ -1,5 +1,5 @@ import { GraphQLResolveInfo, print, responsePathAsArray, SelectionSetNode } from 'graphql'; -import { memoize2of5, memoize5 } from '@graphql-tools/utils'; +import { memoize2of5 } from '@graphql-tools/utils'; import { Subschema } from './Subschema.js'; import { MergedTypeInfo } from './types.js'; From 7dadd9316f1972bf8b60a304e51d33014b74c0dc Mon Sep 17 00:00:00 2001 From: Arda TANRIKULU Date: Mon, 6 May 2024 19:37:52 +0300 Subject: [PATCH 6/6] Fix v15 compat --- packages/federation/test/debug-logging.test.ts | 17 ++++++++--------- 1 file changed, 8 insertions(+), 9 deletions(-) diff --git a/packages/federation/test/debug-logging.test.ts b/packages/federation/test/debug-logging.test.ts index aa85c3e163e..85349b67ab3 100644 --- a/packages/federation/test/debug-logging.test.ts +++ b/packages/federation/test/debug-logging.test.ts @@ -1,9 +1,9 @@ import { readFileSync } from 'fs'; import { join } from 'path'; import { parse } from 'graphql'; -import { buildSubgraphSchema } from '@apollo/subgraph'; import { createDefaultExecutor, delegationPlanInfosByContext } from '@graphql-tools/delegate'; import { normalizedExecutor } from '@graphql-tools/executor'; +import { buildSubgraphSchema } from '../src/subgraph'; import { getStitchedSchemaFromSupergraphSdl } from '../src/supergraph'; import * as accounts from './fixtures/gateway/accounts'; import * as discount from './fixtures/gateway/discount'; @@ -11,15 +11,14 @@ import * as inventory from './fixtures/gateway/inventory'; import * as products from './fixtures/gateway/products'; import * as reviews from './fixtures/gateway/reviews'; -const services: Record = { - accounts, - inventory, - products, - reviews, - discount, -}; - describe('Debug Logging', () => { + const services: Record = { + accounts, + inventory, + products, + reviews, + discount, + }; const existingFlag = process.env['EXPOSE_DELEGATION_PLAN']; const existingMathRandom = Math.random; beforeEach(() => {