From 0fdaa063fa23421aa7a35ba4cd606bacfcf0f035 Mon Sep 17 00:00:00 2001 From: Peter Savchenko Date: Wed, 29 Jul 2026 16:40:22 +0300 Subject: [PATCH 1/5] chore(metrics): notification about slow graphql operations --- src/metrics/graphql.ts | 15 +++ src/metrics/graphqlRequestDetails.ts | 127 +++++++++++++++++++++ src/metrics/mongodb.ts | 40 ++++++- src/metrics/slowOperationAlert.ts | 69 +++++++++++ test/metrics/graphqlRequestDetails.test.ts | 34 ++++++ test/metrics/slowOperationAlert.test.ts | 54 +++++++++ 6 files changed, 337 insertions(+), 2 deletions(-) create mode 100644 src/metrics/graphqlRequestDetails.ts create mode 100644 src/metrics/slowOperationAlert.ts create mode 100644 test/metrics/graphqlRequestDetails.test.ts create mode 100644 test/metrics/slowOperationAlert.test.ts diff --git a/src/metrics/graphql.ts b/src/metrics/graphql.ts index 046d903a..ea59e5f2 100644 --- a/src/metrics/graphql.ts +++ b/src/metrics/graphql.ts @@ -2,6 +2,8 @@ import client from 'prom-client'; import { ApolloServerPlugin, GraphQLRequestContext, GraphQLRequestListener } from 'apollo-server-plugin-base'; import { GraphQLError } from 'graphql'; import HawkCatcher from '@hawk.so/nodejs'; +import { notifySlowOperation } from './slowOperationAlert'; +import { buildGraphqlRequestContext } from './graphqlRequestDetails'; /** * GraphQL operation duration histogram * Tracks GraphQL operation duration by operation name and type @@ -93,6 +95,19 @@ export const graphqlMetricsPlugin: ApolloServerPlugin = { }, }); + notifySlowOperation( + `Slow GraphQL operation: ${operationType} ${operationName}`, + durationMs, + { + operationType, + operationName, + ...buildGraphqlRequestContext(ctx), + ...(hasErrors && { + errors: ctx.errors!.map((error: GraphQLError) => error.message), + }), + } + ); + // Track errors if any if (hasErrors) { ctx.errors!.forEach((error: GraphQLError) => { diff --git a/src/metrics/graphqlRequestDetails.ts b/src/metrics/graphqlRequestDetails.ts new file mode 100644 index 00000000..ee11bd77 --- /dev/null +++ b/src/metrics/graphqlRequestDetails.ts @@ -0,0 +1,127 @@ +import { GraphQLRequestContext } from 'apollo-server-plugin-base'; +import { ResolverContextBase } from '../types/graphql'; +import { truncateText } from './slowOperationAlert'; + +const SENSITIVE_VARIABLE_KEYS = new Set([ + 'password', + 'token', + 'accesstoken', + 'refreshtoken', + 'secret', + 'authorization', +]); + +const HIGHLIGHTED_VARIABLE_KEYS = new Set([ + 'projectid', + 'workspaceid', + 'eventid', + 'originaleventid', + 'release', + 'search', + 'assignee', + 'cursor', +]); + +/** + * Redact sensitive GraphQL variables before sending alerts. + * + * @param value - variable value + * @param key - variable key + * @returns sanitized value + */ +function sanitizeVariableValue(value: unknown, key: string): unknown { + if (SENSITIVE_VARIABLE_KEYS.has(key.toLowerCase())) { + return '[redacted]'; + } + + if (Array.isArray(value)) { + return value.map((item, index) => sanitizeVariableValue(item, `${key}[${index}]`)); + } + + if (value && typeof value === 'object') { + return sanitizeVariables(value as Record); + } + + return value; +} + +/** + * Redact sensitive GraphQL variables before sending alerts. + * + * @param variables - GraphQL request variables + * @returns sanitized variables + */ +function sanitizeVariables(variables: Record | undefined): Record { + if (!variables) { + return {}; + } + + return Object.fromEntries( + Object.entries(variables).map(([key, value]) => [key, sanitizeVariableValue(value, key)]) + ); +} + +/** + * Extract useful identifiers from nested GraphQL variables. + * + * @param value - variable value + * @param prefix - nested path prefix + * @param result - accumulator for extracted ids + * @returns extracted identifiers + */ +function collectHighlightedIds( + value: unknown, + prefix = '', + result: Record = {} +): Record { + if (!value || typeof value !== 'object') { + return result; + } + + for (const [key, nestedValue] of Object.entries(value as Record)) { + const path = prefix ? `${prefix}.${key}` : key; + + if ( + HIGHLIGHTED_VARIABLE_KEYS.has(key.toLowerCase()) && + (typeof nestedValue === 'string' || typeof nestedValue === 'number' || typeof nestedValue === 'boolean') + ) { + result[path] = nestedValue; + continue; + } + + if (nestedValue && typeof nestedValue === 'object' && !Array.isArray(nestedValue)) { + collectHighlightedIds(nestedValue, path, result); + } + } + + return result; +} + +/** + * Build request context for slow GraphQL operation alerts. + * + * @param ctx - GraphQL request context + * @returns alert context + */ +export function buildGraphqlRequestContext(ctx: GraphQLRequestContext): Record { + const context = ctx.context as ResolverContextBase | undefined; + const variables = sanitizeVariables(ctx.request.variables as Record | undefined); + const highlightedIds = collectHighlightedIds(variables); + const alertContext: Record = {}; + + if (context?.user?.id) { + alertContext.userId = context.user.id; + } + + if (Object.keys(highlightedIds).length > 0) { + alertContext.ids = highlightedIds; + } + + const variablesJson = JSON.stringify(variables); + + if (variablesJson && variablesJson !== '{}') { + alertContext.variables = truncateText(variablesJson, 1200); + } + + return alertContext; +} diff --git a/src/metrics/mongodb.ts b/src/metrics/mongodb.ts index a5c1f51d..0ffed4fa 100644 --- a/src/metrics/mongodb.ts +++ b/src/metrics/mongodb.ts @@ -2,6 +2,7 @@ import promClient from 'prom-client'; import { MongoClient, MongoClientOptions } from 'mongodb'; import { Effect, sgr } from '../utils/ansi'; import HawkCatcher from '@hawk.so/nodejs'; +import { notifySlowOperation, truncateText } from './slowOperationAlert'; /** * MongoDB command duration histogram @@ -156,6 +157,7 @@ function colorizeDuration(duration: number): string { */ interface StoredCommandInfo { formattedCommand: string; + plainFormattedCommand: string; timestamp: number; } @@ -202,7 +204,8 @@ setInterval(cleanupStaleCommandInfo, COMMAND_INFO_TIMEOUT_MS); */ function storeCommandInfo(event: any): void { const collectionRaw = extractCollectionFromCommand(event.command, event.commandName); - const collection = sgr(normalizeCollectionName(collectionRaw), Effect.ForegroundGreen); + const collectionName = normalizeCollectionName(collectionRaw); + const collection = sgr(collectionName, Effect.ForegroundGreen); const db = event.databaseName || 'unknown db'; const commandName = sgr(event.commandName, Effect.ForegroundRed); const filter = event.command.filter; @@ -212,11 +215,12 @@ function storeCommandInfo(event: any): void { const params = filter || update || pipeline; const paramsStr = formatParams(params); const projectionStr = projection ? ` projection: ${formatParams(projection)}` : ''; - + const plainFormattedCommand = `[${event.requestId}] ${db}.${collectionName}.${event.commandName}(${paramsStr})${projectionStr}`; const formattedCommand = `[${event.requestId}] ${db}.${collection}.${commandName}(${paramsStr})${projectionStr}`; commandInfoMap.set(event.requestId, { formattedCommand, + plainFormattedCommand, timestamp: Date.now(), }); } @@ -232,9 +236,24 @@ function logCommandSucceeded(event: any): void { if (info) { console.log(`${info.formattedCommand} ✓ ${durationStr}`); + notifySlowOperation( + `Slow MongoDB command: ${event.commandName}`, + event.duration, + { + requestId: event.requestId, + command: truncateText(info.plainFormattedCommand), + } + ); commandInfoMap.delete(event.requestId); } else { console.log(`[${event.requestId}] ${event.commandName} ✓ ${durationStr}`); + notifySlowOperation( + `Slow MongoDB command: ${event.commandName}`, + event.duration, + { + requestId: event.requestId, + } + ); } } @@ -250,9 +269,26 @@ function logCommandFailed(event: any): void { if (info) { console.error(`${info.formattedCommand} ✗ ${errorMsg} ${durationStr}`); + notifySlowOperation( + `Slow MongoDB command: ${event.commandName}`, + event.duration, + { + requestId: event.requestId, + command: truncateText(info.plainFormattedCommand), + error: truncateText(errorMsg, 500), + } + ); commandInfoMap.delete(event.requestId); } else { console.error(`[${event.requestId}] ${event.commandName} ✗ ${errorMsg} ${durationStr}`); + notifySlowOperation( + `Slow MongoDB command: ${event.commandName}`, + event.duration, + { + requestId: event.requestId, + error: truncateText(errorMsg, 500), + } + ); } } diff --git a/src/metrics/slowOperationAlert.ts b/src/metrics/slowOperationAlert.ts new file mode 100644 index 00000000..c4ed7ae8 --- /dev/null +++ b/src/metrics/slowOperationAlert.ts @@ -0,0 +1,69 @@ +import HawkCatcher from '@hawk.so/nodejs'; + +export const SLOW_OPERATION_THRESHOLD_MS = 10000; +const MAX_CONTEXT_STRING_LENGTH = 2500; + +/** + * Truncate text for slow operation context fields. + * + * @param value - text to truncate + * @param maxLength - max allowed length + * @returns truncated text + */ +function truncateText(value: string, maxLength = MAX_CONTEXT_STRING_LENGTH): string { + if (value.length <= maxLength) { + return value; + } + + return `${value.slice(0, maxLength)}…`; +} + +/** + * Truncate long string values in alert context. + * + * @param context - alert context + * @returns sanitized context + */ +function sanitizeContext(context: Record): Record { + return Object.fromEntries( + Object.entries(context).map(([key, value]) => { + if (typeof value === 'string') { + return [key, truncateText(value)]; + } + + return [key, value]; + }) + ); +} + +/** + * Send slow operation alert to Hawk via HawkCatcher. + * + * @param message - short alert message + * @param durationMs - operation duration in milliseconds + * @param context - additional alert context + */ +export function notifySlowOperation( + message: string, + durationMs: number, + context: Record = {} +): void { + if ( + process.env.NODE_ENV === 'test' || + process.env.NODE_ENV === 'e2e' || + durationMs < SLOW_OPERATION_THRESHOLD_MS + ) { + return; + } + + try { + HawkCatcher.send(new Error(message), { + durationMs, + ...sanitizeContext(context), + }); + } catch (error) { + console.log('Couldn\'t send slow operation alert to Hawk', error); + } +} + +export { truncateText }; diff --git a/test/metrics/graphqlRequestDetails.test.ts b/test/metrics/graphqlRequestDetails.test.ts new file mode 100644 index 00000000..8e444ac9 --- /dev/null +++ b/test/metrics/graphqlRequestDetails.test.ts @@ -0,0 +1,34 @@ +import { buildGraphqlRequestContext } from '../../src/metrics/graphqlRequestDetails'; + +describe('buildGraphqlRequestContext', () => { + it('should include user, highlighted ids and sanitized variables', () => { + const context = buildGraphqlRequestContext({ + context: { + user: { + id: 'user-1', + accessTokenExpired: false, + }, + }, + request: { + variables: { + projectId: '6989be3a0bc03531cc430c72', + input: { + workspaceId: 'workspace-1', + password: 'secret', + }, + search: 'TypeError', + }, + }, + } as never); + + expect(context).toEqual({ + userId: 'user-1', + ids: { + projectId: '6989be3a0bc03531cc430c72', + 'input.workspaceId': 'workspace-1', + search: 'TypeError', + }, + variables: '{"projectId":"6989be3a0bc03531cc430c72","input":{"workspaceId":"workspace-1","password":"[redacted]"},"search":"TypeError"}', + }); + }); +}); diff --git a/test/metrics/slowOperationAlert.test.ts b/test/metrics/slowOperationAlert.test.ts new file mode 100644 index 00000000..0fa90d91 --- /dev/null +++ b/test/metrics/slowOperationAlert.test.ts @@ -0,0 +1,54 @@ +import HawkCatcher from '@hawk.so/nodejs'; +import { notifySlowOperation, SLOW_OPERATION_THRESHOLD_MS } from '../../src/metrics/slowOperationAlert'; + +jest.mock('@hawk.so/nodejs', () => ({ + __esModule: true, + default: { + send: jest.fn(), + }, +})); + +describe('slowOperationAlert', () => { + const originalNodeEnv = process.env.NODE_ENV; + + beforeEach(() => { + jest.clearAllMocks(); + process.env.NODE_ENV = 'development'; + }); + + afterAll(() => { + process.env.NODE_ENV = originalNodeEnv; + }); + + it('should send Hawk alert for slow operations', () => { + notifySlowOperation('Slow GraphQL operation: query ProjectDailyEvents', SLOW_OPERATION_THRESHOLD_MS, { + projectId: 'project-1', + }); + + expect(HawkCatcher.send).toHaveBeenCalledWith( + expect.objectContaining({ message: 'Slow GraphQL operation: query ProjectDailyEvents' }), + { + durationMs: SLOW_OPERATION_THRESHOLD_MS, + projectId: 'project-1', + } + ); + }); + + it('should not send Hawk alert for fast operations', () => { + notifySlowOperation('fast op', SLOW_OPERATION_THRESHOLD_MS - 1, { + projectId: 'project-1', + }); + + expect(HawkCatcher.send).not.toHaveBeenCalled(); + }); + + it('should not send Hawk alert in test environment', () => { + process.env.NODE_ENV = 'test'; + + notifySlowOperation('slow op', SLOW_OPERATION_THRESHOLD_MS, { + projectId: 'project-1', + }); + + expect(HawkCatcher.send).not.toHaveBeenCalled(); + }); +}); From eeb798b29a1e04a13777156c63eed76fc08447e2 Mon Sep 17 00:00:00 2001 From: github-actions <41898282+github-actions[bot]@users.noreply.github.com> Date: Mon, 10 Aug 2026 19:11:25 +0000 Subject: [PATCH 2/5] Bump version up to 1.5.7 --- package.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/package.json b/package.json index 1e9ebca4..6582959a 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "hawk.api", - "version": "1.5.6", + "version": "1.5.7", "main": "index.ts", "license": "BUSL-1.1", "scripts": { From 3357a4f85a247282984ec2e8c5781f11718aca89 Mon Sep 17 00:00:00 2001 From: Peter Savchenko Date: Mon, 10 Aug 2026 22:27:04 +0300 Subject: [PATCH 3/5] upd corner cases --- src/metrics/graphql.ts | 4 +- src/metrics/graphqlRequestDetails.ts | 36 +++++++++++++++-- test/metrics/graphqlRequestDetails.test.ts | 47 +++++++++++++++++++++- 3 files changed, 81 insertions(+), 6 deletions(-) diff --git a/src/metrics/graphql.ts b/src/metrics/graphql.ts index ea59e5f2..3cec26cc 100644 --- a/src/metrics/graphql.ts +++ b/src/metrics/graphql.ts @@ -3,7 +3,7 @@ import { ApolloServerPlugin, GraphQLRequestContext, GraphQLRequestListener } fro import { GraphQLError } from 'graphql'; import HawkCatcher from '@hawk.so/nodejs'; import { notifySlowOperation } from './slowOperationAlert'; -import { buildGraphqlRequestContext } from './graphqlRequestDetails'; +import { buildGraphqlRequestContext, formatGraphqlErrorsForAlert } from './graphqlRequestDetails'; /** * GraphQL operation duration histogram * Tracks GraphQL operation duration by operation name and type @@ -103,7 +103,7 @@ export const graphqlMetricsPlugin: ApolloServerPlugin = { operationName, ...buildGraphqlRequestContext(ctx), ...(hasErrors && { - errors: ctx.errors!.map((error: GraphQLError) => error.message), + errors: formatGraphqlErrorsForAlert(ctx.errors!), }), } ); diff --git a/src/metrics/graphqlRequestDetails.ts b/src/metrics/graphqlRequestDetails.ts index ee11bd77..06720121 100644 --- a/src/metrics/graphqlRequestDetails.ts +++ b/src/metrics/graphqlRequestDetails.ts @@ -1,7 +1,11 @@ import { GraphQLRequestContext } from 'apollo-server-plugin-base'; +import { GraphQLError } from 'graphql'; import { ResolverContextBase } from '../types/graphql'; import { truncateText } from './slowOperationAlert'; +const MAX_ALERT_ERRORS = 10; +const MAX_ALERT_ERRORS_LENGTH = 1200; + const SENSITIVE_VARIABLE_KEYS = new Set([ 'password', 'token', @@ -51,8 +55,15 @@ function sanitizeVariableValue(value: unknown, key: string): unknown { * @param variables - GraphQL request variables * @returns sanitized variables */ -function sanitizeVariables(variables: Record | undefined): Record { - if (!variables) { +function sanitizeVariables( + variables: Record | null | undefined +): Record { + /** + * Null / non-object values are treated as empty — many clients send + * `variables: null` for operations without variables, and arrays are not a + * valid GraphQL variables map. + */ + if (variables == null || typeof variables !== 'object' || Array.isArray(variables)) { return {}; } @@ -97,6 +108,23 @@ function collectHighlightedIds( return result; } +/** + * Flatten GraphQL errors into a capped string for Hawk alert context. + * sanitizeContext() only truncates top-level strings, not values nested in arrays. + * Reserves space for an omitted-count suffix and truncateText()'s ellipsis. + * + * @param errors - GraphQL errors from the request + * @returns flattened and truncated error messages + */ +export function formatGraphqlErrorsForAlert(errors: readonly GraphQLError[]): string { + const messages = errors.slice(0, MAX_ALERT_ERRORS).map((error) => error.message); + const omittedCount = errors.length - messages.length; + const omittedSuffix = omittedCount > 0 ? `; …(+${omittedCount} more)` : ''; + const maxMessagesLength = Math.max(0, MAX_ALERT_ERRORS_LENGTH - omittedSuffix.length - 1); + + return `${truncateText(messages.join('; '), maxMessagesLength)}${omittedSuffix}`; +} + /** * Build request context for slow GraphQL operation alerts. * @@ -105,7 +133,9 @@ function collectHighlightedIds( */ export function buildGraphqlRequestContext(ctx: GraphQLRequestContext): Record { const context = ctx.context as ResolverContextBase | undefined; - const variables = sanitizeVariables(ctx.request.variables as Record | undefined); + const variables = sanitizeVariables( + ctx.request.variables as Record | null | undefined + ); const highlightedIds = collectHighlightedIds(variables); const alertContext: Record = {}; diff --git a/test/metrics/graphqlRequestDetails.test.ts b/test/metrics/graphqlRequestDetails.test.ts index 8e444ac9..f7a3542f 100644 --- a/test/metrics/graphqlRequestDetails.test.ts +++ b/test/metrics/graphqlRequestDetails.test.ts @@ -1,4 +1,8 @@ -import { buildGraphqlRequestContext } from '../../src/metrics/graphqlRequestDetails'; +import { GraphQLError } from 'graphql'; +import { + buildGraphqlRequestContext, + formatGraphqlErrorsForAlert, +} from '../../src/metrics/graphqlRequestDetails'; describe('buildGraphqlRequestContext', () => { it('should include user, highlighted ids and sanitized variables', () => { @@ -31,4 +35,45 @@ describe('buildGraphqlRequestContext', () => { variables: '{"projectId":"6989be3a0bc03531cc430c72","input":{"workspaceId":"workspace-1","password":"[redacted]"},"search":"TypeError"}', }); }); + + it('should tolerate null GraphQL variables', () => { + const context = buildGraphqlRequestContext({ + context: { + user: { + id: 'user-1', + accessTokenExpired: false, + }, + }, + request: { + variables: null, + }, + } as never); + + expect(context).toEqual({ + userId: 'user-1', + }); + }); +}); + +describe('formatGraphqlErrorsForAlert', () => { + it('should flatten error messages into a single string', () => { + const text = formatGraphqlErrorsForAlert([ + new GraphQLError('First error'), + new GraphQLError('Second error'), + ]); + + expect(text).toBe('First error; Second error'); + }); + + it('should cap the number of errors and truncate long payloads', () => { + const errors = Array.from({ length: 12 }, (_, index) => { + return new GraphQLError(`validation failed on field_${index}: ${'x'.repeat(200)}`); + }); + const text = formatGraphqlErrorsForAlert(errors); + + expect(text.startsWith('validation failed on field_0:')).toBe(true); + expect(text).toContain('…(+2 more)'); + expect(text).toContain('…; …(+2 more)'); + expect(text.length).toBeLessThanOrEqual(1200); + }); }); From ace3500a3c89d674d010cb6d2804ce08b2da5aa7 Mon Sep 17 00:00:00 2001 From: github-actions <41898282+github-actions[bot]@users.noreply.github.com> Date: Mon, 10 Aug 2026 19:27:44 +0000 Subject: [PATCH 4/5] Bump version up to 1.5.9 --- package.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/package.json b/package.json index 9b7c317a..c2a99968 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "hawk.api", - "version": "1.5.8", + "version": "1.5.9", "main": "index.ts", "license": "BUSL-1.1", "scripts": { From f345276e785d622e123d8fe14790b56b94f6d72c Mon Sep 17 00:00:00 2001 From: Peter Savchenko Date: Mon, 10 Aug 2026 22:34:43 +0300 Subject: [PATCH 5/5] Update graphqlRequestDetails.ts --- src/metrics/graphqlRequestDetails.ts | 1 + 1 file changed, 1 insertion(+) diff --git a/src/metrics/graphqlRequestDetails.ts b/src/metrics/graphqlRequestDetails.ts index 06720121..aacd09b8 100644 --- a/src/metrics/graphqlRequestDetails.ts +++ b/src/metrics/graphqlRequestDetails.ts @@ -43,6 +43,7 @@ function sanitizeVariableValue(value: unknown, key: string): unknown { } if (value && typeof value === 'object') { + // eslint-disable-next-line @typescript-eslint/no-use-before-define return sanitizeVariables(value as Record); }