From dff07edf87c94253ce551cb15cc96ff2facacb9f Mon Sep 17 00:00:00 2001 From: Iain Sproat <68657+iainsproat@users.noreply.github.com> Date: Mon, 14 Apr 2025 18:17:37 +0100 Subject: [PATCH] chore(server/core/logging): add operation logging to mutations --- .../modules/core/graph/resolvers/apitoken.ts | 28 +++- .../modules/core/graph/resolvers/appTokens.ts | 23 ++- .../modules/core/graph/resolvers/branches.ts | 63 +++++-- .../modules/core/graph/resolvers/commits.ts | 155 ++++++++++++++---- .../modules/core/graph/resolvers/models.ts | 70 ++++++-- .../modules/core/graph/resolvers/objects.ts | 28 +++- .../observability/domain/businessLogging.ts | 8 + 7 files changed, 303 insertions(+), 72 deletions(-) diff --git a/packages/server/modules/core/graph/resolvers/apitoken.ts b/packages/server/modules/core/graph/resolvers/apitoken.ts index 310503e69..cfcbb36af 100644 --- a/packages/server/modules/core/graph/resolvers/apitoken.ts +++ b/packages/server/modules/core/graph/resolvers/apitoken.ts @@ -11,6 +11,7 @@ import { } from '@/modules/core/repositories/tokens' import { Resolvers } from '@/modules/core/graph/generated/graphql' import { createPersonalAccessTokenFactory } from '@/modules/core/services/tokens' +import { withOperationLogging } from '@/observability/domain/businessLogging' const createPersonalAccessToken = createPersonalAccessTokenFactory({ storeApiToken: storeApiTokenFactory({ db }), @@ -44,18 +45,33 @@ const resolvers = { } }) - return await createPersonalAccessToken( - context.userId!, - args.token.name, - args.token.scopes.filter(isValidScope), - args.token.lifespan || undefined + return await withOperationLogging( + async () => + await createPersonalAccessToken( + context.userId!, + args.token.name, + args.token.scopes.filter(isValidScope), + args.token.lifespan || undefined + ), + { + logger: context.log, + operationName: 'createPersonalAccessToken', + operationDescription: `Create a new Personal Access Token` + } ) }, async apiTokenRevoke(_parent, args, context) { let id = null if (args.token.toLowerCase().includes('bearer')) id = args.token.split(' ')[1] else id = args.token - await revokeToken(id, context.userId!) // let's not revoke other people's tokens + await withOperationLogging( + async () => await revokeToken(id, context.userId!), // let's not revoke other people's tokens + { + logger: context.log, + operationName: 'revokePersonalAccessToken', + operationDescription: `Revoke a Personal Access Token` + } + ) return true } } diff --git a/packages/server/modules/core/graph/resolvers/appTokens.ts b/packages/server/modules/core/graph/resolvers/appTokens.ts index 9160666ba..6090f2d42 100644 --- a/packages/server/modules/core/graph/resolvers/appTokens.ts +++ b/packages/server/modules/core/graph/resolvers/appTokens.ts @@ -9,6 +9,7 @@ import { storeUserServerAppTokenFactory } from '@/modules/core/repositories/tokens' import { createAppTokenFactory } from '@/modules/core/services/tokens' +import { withOperationLogging } from '@/observability/domain/businessLogging' const getTokenAppInfo = getTokenAppInfoFactory({ db }) const createAppToken = createAppTokenFactory({ @@ -50,13 +51,21 @@ export = { }) const scopes = args.token.scopes.filter(isValidScope) - const token = await createAppToken({ - ...args.token, - userId: ctx.userId!, - appId, - lifespan: args.token.lifespan || undefined, - scopes - }) + const token = await withOperationLogging( + async () => + await createAppToken({ + ...args.token, + userId: ctx.userId!, + appId, + lifespan: args.token.lifespan || undefined, + scopes + }), + { + logger: ctx.log, + operationName: 'createAppToken', + operationDescription: `Create a new App Token` + } + ) return token } } diff --git a/packages/server/modules/core/graph/resolvers/branches.ts b/packages/server/modules/core/graph/resolvers/branches.ts index 5cc2b6227..4d914eb9c 100644 --- a/packages/server/modules/core/graph/resolvers/branches.ts +++ b/packages/server/modules/core/graph/resolvers/branches.ts @@ -32,6 +32,7 @@ import { throwIfAuthNotOk } from '@/modules/shared/helpers/errorHelper' import { throwIfResourceAccessNotAllowed } from '@/modules/core/helpers/token' +import { withOperationLogging } from '@/observability/domain/businessLogging' export = { Query: {}, @@ -83,66 +84,101 @@ export = { resourceAccessRules: context.resourceAccessRules }) + const projectId = args.branch.streamId + + const logger = context.log.child({ + projectId, + streamId: projectId //legacy + }) + const canCreate = await context.authPolicies.project.model.canCreate({ userId: context.userId, - projectId: args.branch.streamId + projectId }) if (!canCreate.isOk) { throw mapAuthToServerError(canCreate.error) } - const projectDB = await getProjectDbClient({ projectId: args.branch.streamId }) + const projectDB = await getProjectDbClient({ projectId }) const getStreamBranchByName = getStreamBranchByNameFactory({ db: projectDB }) const createBranchAndNotify = createBranchAndNotifyFactory({ getStreamBranchByName, createBranch: createBranchFactory({ db: projectDB }), eventEmit: getEventBus().emit }) - const { id } = await createBranchAndNotify(args.branch, context.userId!) + const { id } = await withOperationLogging( + async () => await createBranchAndNotify(args.branch, context.userId!), + { + logger, + operationName: 'createBranch', + operationDescription: `Create a new Branch` + } + ) return id }, async branchUpdate(_parent, args, ctx) { + const projectId = args.branch.streamId throwIfResourceAccessNotAllowed({ resourceId: args.branch.streamId, resourceAccessRules: ctx.resourceAccessRules, resourceType: TokenResourceIdentifierType.Project }) + const logger = ctx.log.child({ + projectId, + streamId: projectId //legacy + }) + const canUpdate = await ctx.authPolicies.project.model.canUpdate({ userId: ctx.userId, - projectId: args.branch.streamId + projectId }) throwIfAuthNotOk(canUpdate) - const projectDB = await getProjectDbClient({ projectId: args.branch.streamId }) + const projectDB = await getProjectDbClient({ projectId }) const getBranchById = getBranchByIdFactory({ db: projectDB }) const updateBranchAndNotify = updateBranchAndNotifyFactory({ getBranchById, updateBranch: updateBranchFactory({ db: projectDB }), eventEmit: getEventBus().emit }) - const newBranch = await updateBranchAndNotify(args.branch, ctx.userId!) + const newBranch = await withOperationLogging( + async () => await updateBranchAndNotify(args.branch, ctx.userId!), + { + logger, + operationName: 'updateBranch', + operationDescription: `Update a Branch` + } + ) return !!newBranch }, async branchDelete(_parent, args, context) { + const projectId = args.branch.streamId + const modelId = args.branch.id throwIfResourceAccessNotAllowed({ resourceId: args.branch.streamId, resourceAccessRules: context.resourceAccessRules, resourceType: TokenResourceIdentifierType.Project }) + const logger = context.log.child({ + projectId, + streamId: projectId, //legacy + modelId + }) + const canDelete = await context.authPolicies.project.model.canDelete({ userId: context.userId, - projectId: args.branch.streamId, - modelId: args.branch.id + projectId, + modelId }) throwIfAuthNotOk(canDelete) - const projectDB = await getProjectDbClient({ projectId: args.branch.streamId }) + const projectDB = await getProjectDbClient({ projectId }) const markBranchStreamUpdated = markBranchStreamUpdatedFactory({ db: projectDB }) const getStream = getStreamFactory({ db: projectDB }) const deleteBranchAndNotify = deleteBranchAndNotifyFactory({ @@ -152,7 +188,14 @@ export = { markBranchStreamUpdated, deleteBranchById: deleteBranchByIdFactory({ db: projectDB }) }) - const deleted = await deleteBranchAndNotify(args.branch, context.userId!) + const deleted = await withOperationLogging( + async () => await deleteBranchAndNotify(args.branch, context.userId!), + { + logger, + operationName: 'deleteBranch', + operationDescription: `Delete a Branch` + } + ) return deleted } }, diff --git a/packages/server/modules/core/graph/resolvers/commits.ts b/packages/server/modules/core/graph/resolvers/commits.ts index e35f6da92..48fdf69c9 100644 --- a/packages/server/modules/core/graph/resolvers/commits.ts +++ b/packages/server/modules/core/graph/resolvers/commits.ts @@ -82,6 +82,7 @@ import { TokenResourceIdentifierType } from '@/modules/core/domain/tokens/types' import { throwIfAuthNotOk } from '@/modules/shared/helpers/errorHelper' import { getFeatureFlags } from '@/modules/shared/helpers/envHelper' import { getDateFromLimitsFactory } from '@/modules/core/services/versions/limits' +import { withOperationLogging } from '@/observability/domain/businessLogging' const { FF_FORCE_PERSONAL_PROJECTS_LIMITS_ENABLED } = getFeatureFlags() @@ -361,6 +362,15 @@ export = { throw new RateLimitError(rateLimitResult) } + const projectId = args.commit.streamId + const modelName = args.commit.branchName + const logger = context.log.child({ + projectId, + streamId: projectId, //legacy + modelName, + branchName: modelName //legacy + }) + throwIfResourceAccessNotAllowed({ resourceId: args.commit.streamId, resourceType: TokenResourceIdentifierType.Project, @@ -368,15 +378,15 @@ export = { }) const canCreate = await context.authPolicies.project.version.canCreate({ userId: context.userId, - projectId: args.commit.streamId + projectId }) throwIfAuthNotOk(canCreate) await coreModule.executeHooks('onCreateVersionRequest', { - projectId: args.commit.streamId + projectId }) - const projectDb = await getProjectDbClient({ projectId: args.commit.streamId }) + const projectDb = await getProjectDbClient({ projectId }) const createCommitByBranchId = createCommitByBranchIdFactory({ createCommit: createCommitFactory({ db: projectDb }), @@ -395,21 +405,38 @@ export = { getBranchById: getBranchByIdFactory({ db: projectDb }) }) - const { id } = await createCommitByBranchName({ - ...args.commit, - parents: args.commit.parents?.filter(isNonNullable), - authorId: context.userId! - }) + const { id } = await withOperationLogging( + async () => + await createCommitByBranchName({ + ...args.commit, + parents: args.commit.parents?.filter(isNonNullable), + authorId: context.userId! + }), + { + logger, + operationName: 'createCommit', + operationDescription: `Create a new Commit` + } + ) return id }, async commitUpdate(_parent, args, context) { + const projectId = args.commit.streamId + const commitId = args.commit.id throwIfResourceAccessNotAllowed({ resourceId: args.commit.streamId, resourceType: TokenResourceIdentifierType.Project, resourceAccessRules: context.resourceAccessRules }) + + const logger = context.log.child({ + projectId, + streamId: projectId, //legacy + commitId + }) + const canUpdate = await context.authPolicies.project.version.canUpdate({ userId: context.userId, projectId: args.commit.streamId, @@ -430,48 +457,83 @@ export = { markCommitStreamUpdated: markCommitStreamUpdatedFactory({ db: projectDb }), markCommitBranchUpdated: markCommitBranchUpdatedFactory({ db: projectDb }) }) - await updateCommitAndNotify(args.commit, context.userId!) + await withOperationLogging( + async () => await updateCommitAndNotify(args.commit, context.userId!), + { + logger, + operationName: 'updateCommit', + operationDescription: `Update a Commit` + } + ) return true }, async commitReceive(_parent, args, context) { + const projectId = args.input.streamId + const versionId = args.input.commitId throwIfResourceAccessNotAllowed({ resourceId: args.input.streamId, resourceType: TokenResourceIdentifierType.Project, resourceAccessRules: context.resourceAccessRules }) + + const logger = context.log.child({ + projectId, + streamId: projectId, //legacy, + versionId, + commitId: versionId //legacy + }) + const canReceive = await context.authPolicies.project.version.canReceive({ userId: context.userId, - projectId: args.input.streamId + projectId }) throwIfAuthNotOk(canReceive) - const projectDb = await getProjectDbClient({ projectId: args.input.streamId }) - await markCommitReceivedAndNotifyFactory({ - getCommit: getCommitFactory({ db: projectDb }), - emitEvent: getEventBus().emit - })({ - input: args.input, - userId: context.userId! - }) + const projectDb = await getProjectDbClient({ projectId }) + await withOperationLogging( + async () => + await markCommitReceivedAndNotifyFactory({ + getCommit: getCommitFactory({ db: projectDb }), + emitEvent: getEventBus().emit + })({ + input: args.input, + userId: context.userId! + }), + { + logger, + operationName: 'receiveCommit', + operationDescription: `Receive a Commit` + } + ) return true }, async commitDelete(_parent, args, context) { + const projectId = args.commit.streamId + const versionId = args.commit.id throwIfResourceAccessNotAllowed({ - resourceId: args.commit.streamId, + resourceId: projectId, resourceType: TokenResourceIdentifierType.Project, resourceAccessRules: context.resourceAccessRules }) + + const logger = context.log.child({ + projectId, + streamId: projectId, //legacy + versionId, + commitId: versionId //legacy + }) + const canUpdate = await context.authPolicies.project.version.canUpdate({ userId: context.userId, - projectId: args.commit.streamId, - versionId: args.commit.id + projectId, + versionId }) throwIfAuthNotOk(canUpdate) - const projectDb = await getProjectDbClient({ projectId: args.commit.streamId }) + const projectDb = await getProjectDbClient({ projectId }) const deleteCommitAndNotify = deleteCommitAndNotifyFactory({ getCommit: getCommitFactory({ db: projectDb }), markCommitStreamUpdated: markCommitStreamUpdatedFactory({ db: projectDb }), @@ -479,22 +541,33 @@ export = { deleteCommit: deleteCommitFactory({ db: projectDb }), emitEvent: getEventBus().emit }) - const deleted = await deleteCommitAndNotify( - args.commit.id, - args.commit.streamId, - context.userId! + const deleted = await withOperationLogging( + async () => + await deleteCommitAndNotify(args.commit.id, projectId, context.userId!), + { + logger, + operationName: 'deleteCommit', + operationDescription: 'Delete a Commit' + } ) return deleted }, // Not used by connectors async commitsMove(_, args, ctx) { + const projectId = args.input.streamId + throwIfResourceAccessNotAllowed({ resourceId: args.input.streamId, resourceType: TokenResourceIdentifierType.Project, resourceAccessRules: ctx.resourceAccessRules }) + const logger = ctx.log.child({ + projectId, + streamId: projectId //legacy + }) + const canUpdateAll = await Promise.all( args.input.commitIds.map(async (versionId) => ctx.authPolicies.project.version.canUpdate({ @@ -517,23 +590,36 @@ export = { moveCommitsToBranch: moveCommitsToBranchFactory({ db: projectDb }), emitEvent: getEventBus().emit }) - await batchMoveCommits(args.input, ctx.userId!) + await withOperationLogging( + async () => await batchMoveCommits(args.input, ctx.userId!), + { + logger, + operationName: 'moveCommits', + operationDescription: 'Move one or more commits' + } + ) return true }, // Not used by connectors async commitsDelete(_, args, ctx) { + const projectId = args.input.streamId throwIfResourceAccessNotAllowed({ - resourceId: args.input.streamId, + resourceId: projectId, resourceType: TokenResourceIdentifierType.Project, resourceAccessRules: ctx.resourceAccessRules }) + const logger = ctx.log.child({ + projectId, + streamId: projectId //legacy + }) + const canUpdateAll = await Promise.all( args.input.commitIds.map(async (versionId) => ctx.authPolicies.project.version.canUpdate({ userId: ctx.userId, - projectId: args.input.streamId, + projectId, versionId }) ) @@ -542,14 +628,21 @@ export = { throwIfAuthNotOk(result) }) - const projectDb = await getProjectDbClient({ projectId: args.input.streamId }) + const projectDb = await getProjectDbClient({ projectId }) const batchDeleteCommits = batchDeleteCommitsFactory({ getCommits: getCommitsFactory({ db: projectDb }), getStreams, deleteCommits: deleteCommitsFactory({ db: projectDb }), emitEvent: getEventBus().emit }) - await batchDeleteCommits(args.input, ctx.userId!) + await withOperationLogging( + async () => await batchDeleteCommits(args.input, ctx.userId!), + { + logger, + operationName: 'deleteCommits', + operationDescription: 'Delete one or more commits' + } + ) return true } }, diff --git a/packages/server/modules/core/graph/resolvers/models.ts b/packages/server/modules/core/graph/resolvers/models.ts index 565ce65c2..cac888949 100644 --- a/packages/server/modules/core/graph/resolvers/models.ts +++ b/packages/server/modules/core/graph/resolvers/models.ts @@ -59,6 +59,7 @@ import { getEventBus } from '@/modules/shared/services/eventBus' import { throwIfAuthNotOk } from '@/modules/shared/helpers/errorHelper' import { throwIfResourceAccessNotAllowed } from '@/modules/core/helpers/token' import { TokenResourceIdentifierType } from '@/modules/core/domain/tokens/types' +import { withOperationLogging } from '@/observability/domain/businessLogging' export = { User: { @@ -297,19 +298,25 @@ export = { }, ModelMutations: { async create(_parent, args, ctx) { + const projectId = args.input.projectId throwIfResourceAccessNotAllowed({ - resourceId: args.input.projectId, + resourceId: projectId, resourceAccessRules: ctx.resourceAccessRules, resourceType: TokenResourceIdentifierType.Project }) + const logger = ctx.log.child({ + projectId, + streamId: projectId //legacy + }) + const canCreate = await ctx.authPolicies.project.model.canCreate({ userId: ctx.userId, - projectId: args.input.projectId + projectId }) throwIfAuthNotOk(canCreate) - const projectDB = await getProjectDbClient({ projectId: args.input.projectId }) + const projectDB = await getProjectDbClient({ projectId }) // Sanitize model name by trimming spaces around slashes const sanitizedInput = { @@ -326,44 +333,76 @@ export = { createBranch: createBranchFactory({ db: projectDB }), eventEmit: getEventBus().emit }) - return await createBranchAndNotify(sanitizedInput, ctx.userId!) + return await withOperationLogging( + async () => await createBranchAndNotify(sanitizedInput, ctx.userId!), + { + logger, + operationName: 'createModel', + operationDescription: `Create a new Model` + } + ) }, async update(_parent, args, ctx) { + const projectId = args.input.projectId + const modelId = args.input.id throwIfResourceAccessNotAllowed({ - resourceId: args.input.projectId, + resourceId: projectId, resourceAccessRules: ctx.resourceAccessRules, resourceType: TokenResourceIdentifierType.Project }) + const logger = ctx.log.child({ + projectId, + streamId: projectId, //legacy + modelId, + branchId: modelId //legacy + }) + const canUpdate = await ctx.authPolicies.project.model.canUpdate({ userId: ctx.userId, - projectId: args.input.projectId + projectId }) throwIfAuthNotOk(canUpdate) - const projectDB = await getProjectDbClient({ projectId: args.input.projectId }) + const projectDB = await getProjectDbClient({ projectId }) const updateBranchAndNotify = updateBranchAndNotifyFactory({ getBranchById: getBranchByIdFactory({ db: projectDB }), updateBranch: updateBranchFactory({ db: projectDB }), eventEmit: getEventBus().emit }) - return await updateBranchAndNotify(args.input, ctx.userId!) + return await withOperationLogging( + async () => await updateBranchAndNotify(args.input, ctx.userId!), + { + logger, + operationName: 'updateModel', + operationDescription: `Update a Model` + } + ) }, async delete(_parent, args, ctx) { + const projectId = args.input.projectId + const modelId = args.input.id throwIfResourceAccessNotAllowed({ resourceId: args.input.projectId, resourceAccessRules: ctx.resourceAccessRules, resourceType: TokenResourceIdentifierType.Project }) + const logger = ctx.log.child({ + projectId, + streamId: projectId, //legacy + modelId, + branchId: modelId //legacy + }) + const canDelete = await ctx.authPolicies.project.model.canDelete({ userId: ctx.userId, - projectId: args.input.projectId, - modelId: args.input.id + projectId, + modelId }) throwIfAuthNotOk(canDelete) - const projectDB = await getProjectDbClient({ projectId: args.input.projectId }) + const projectDB = await getProjectDbClient({ projectId }) const markBranchStreamUpdated = markBranchStreamUpdatedFactory({ db: projectDB }) const getStream = getStreamFactory({ db }) const deleteBranchAndNotify = deleteBranchAndNotifyFactory({ @@ -373,7 +412,14 @@ export = { markBranchStreamUpdated, deleteBranchById: deleteBranchByIdFactory({ db: projectDB }) }) - return await deleteBranchAndNotify(args.input, ctx.userId!) + return await withOperationLogging( + async () => await deleteBranchAndNotify(args.input, ctx.userId!), + { + logger, + operationName: 'deleteModel', + operationDescription: `Delete a Model` + } + ) } }, Subscription: { diff --git a/packages/server/modules/core/graph/resolvers/objects.ts b/packages/server/modules/core/graph/resolvers/objects.ts index 66cef6e1a..e2f60754f 100644 --- a/packages/server/modules/core/graph/resolvers/objects.ts +++ b/packages/server/modules/core/graph/resolvers/objects.ts @@ -10,6 +10,7 @@ import { import { createObjectsFactory } from '@/modules/core/services/objects/management' import { getProjectDbClient } from '@/modules/multiregion/utils/dbSelector' import coreModule from '@/modules/core' +import { withOperationLogging } from '@/observability/domain/businessLogging' type GetObjectChildrenQueryParams = Parameters< ReturnType @@ -93,6 +94,8 @@ export = { }, Mutation: { async objectCreate(_parent, args, context) { + const projectId = args.objectInput.streamId + await authorizeResolver( context.userId, args.objectInput.streamId, @@ -100,20 +103,33 @@ export = { context.resourceAccessRules ) + const logger = context.log.child({ + projectId, + streamId: projectId //legacy + }) + await coreModule.executeHooks?.('onCreateObjectRequest', { - projectId: args.objectInput.streamId + projectId }) const projectDB = await getProjectDbClient({ - projectId: args.objectInput.streamId + projectId }) const createObjects = createObjectsFactory({ storeObjectsIfNotFoundFactory: storeObjectsIfNotFoundFactory({ db: projectDB }) }) - const ids = await createObjects({ - streamId: args.objectInput.streamId, - objects: args.objectInput.objects.filter(isNonNullable) - }) + const ids = await withOperationLogging( + async () => + await createObjects({ + streamId: projectId, + objects: args.objectInput.objects.filter(isNonNullable) + }), + { + logger, + operationName: 'objectCreate', + operationDescription: `Create one or more new objects` + } + ) return ids } } diff --git a/packages/server/observability/domain/businessLogging.ts b/packages/server/observability/domain/businessLogging.ts index 1e545bc84..d5b08221d 100644 --- a/packages/server/observability/domain/businessLogging.ts +++ b/packages/server/observability/domain/businessLogging.ts @@ -12,6 +12,14 @@ export const logErrorThenThrow = (err: unknown, logger: Logger) => { throw err } +/** + * @description withOperationLogging is intended to be used for adding observability to high-level 'business' operations + * (e.g. creating a new object, sending an email, etc). It will log the start and end of the operation, as well as any errors that occur. + * It is likely to only be called directly within mutation Graphql resolvers and POST/PUT/DELETE REST endpoints. + * @param operation + * @param params + * @returns Returns the result of the operation + */ export const withOperationLogging = async ( operation: () => T, params: {