diff --git a/packages/core/src/app/init.test.ts b/packages/core/src/app/init.test.ts index f750a27a7..3ab0c1d7b 100644 --- a/packages/core/src/app/init.test.ts +++ b/packages/core/src/app/init.test.ts @@ -1,4 +1,4 @@ -import { mockEsmDefault, pickDefault } from '@logto/shared/esm'; +import { mockEsm, pickDefault } from '@logto/shared/esm'; import Koa from 'koa'; import { emptyMiddleware } from '#src/utils/test-utils.js'; @@ -14,7 +14,10 @@ const middlewareList = [ 'spa-proxy', ].map((name) => { const mock = jest.fn(() => emptyMiddleware); - mockEsmDefault(`#src/middleware/koa-${name}.js`, () => mock); + mockEsm(`#src/middleware/koa-${name}.js`, () => ({ + default: mock, + ...(name === 'audit-log' && { LogEntry: jest.fn() }), + })); return mock; }); diff --git a/packages/core/src/libraries/hook.test.ts b/packages/core/src/libraries/hook.test.ts index 8991cfafd..75ae591da 100644 --- a/packages/core/src/libraries/hook.test.ts +++ b/packages/core/src/libraries/hook.test.ts @@ -1,4 +1,4 @@ -import { InteractionEvent } from '@logto/schemas'; +import { InteractionEvent, LogResult } from '@logto/schemas'; import { HookEvent } from '@logto/schemas/lib/models/hooks.js'; import { mockEsm, mockEsmDefault } from '@logto/shared/esm'; import type { InferModelType } from '@withtyped/server'; @@ -25,8 +25,20 @@ const readAll = jest .spyOn(modelRouters.hook.client, 'readAll') .mockResolvedValue({ rows: [hook], rowCount: 1 }); -// @ts-expect-error for testing -const post = jest.spyOn(got, 'post').mockImplementation(jest.fn(() => ({ json: jest.fn() }))); +const post = jest + .spyOn(got, 'post') + // @ts-expect-error for testing + .mockImplementation(jest.fn(async () => ({ statusCode: 200, body: '{"message":"ok"}' }))); + +// TODO: @Gao fix `mockEsm()` import issue +const nanoIdMock = 'mockId'; +jest.unstable_mockModule('@logto/core-kit', () => ({ + generateStandardId: () => nanoIdMock, +})); + +const { insertLog } = mockEsm('#src/queries/log.js', () => ({ + insertLog: jest.fn(), +})); mockEsm('#src/queries/user.js', () => ({ findUserById: () => ({ id: 'user_id', username: 'user', extraField: 'not_ok' }), @@ -47,7 +59,7 @@ describe('triggerInteractionHooksIfNeeded()', () => { }); it('should return if no user ID found', async () => { - await triggerInteractionHooksIfNeeded(); + await triggerInteractionHooksIfNeeded(InteractionEvent.SignIn); expect(queryFunction).not.toBeCalled(); }); @@ -56,14 +68,11 @@ describe('triggerInteractionHooksIfNeeded()', () => { jest.useFakeTimers().setSystemTime(100_000); await triggerInteractionHooksIfNeeded( + InteractionEvent.SignIn, // @ts-expect-error for testing { jti: 'some_jti', - result: { - login: { accountId: '123' }, - event: InteractionEvent.SignIn, - identifier: { connectorId: 'bar' }, - }, + result: { login: { accountId: '123' } }, params: { client_id: 'some_client' }, } as Interaction ); @@ -84,6 +93,18 @@ describe('triggerInteractionHooksIfNeeded()', () => { retry: { limit: 3 }, timeout: { request: 10_000 }, }); + + const calledPayload: unknown = insertLog.mock.calls[0][0]; + expect(calledPayload).toHaveProperty('id', nanoIdMock); + expect(calledPayload).toHaveProperty('key', 'TriggerHook.' + HookEvent.PostSignIn); + expect(calledPayload).toHaveProperty('payload.result', LogResult.Success); + expect(calledPayload).toHaveProperty('payload.hookId', 'foo'); + expect(calledPayload).toHaveProperty('payload.json.event', HookEvent.PostSignIn); + expect(calledPayload).toHaveProperty('payload.json.interactionEvent', InteractionEvent.SignIn); + expect(calledPayload).toHaveProperty('payload.json.hookId', 'foo'); + expect(calledPayload).toHaveProperty('payload.json.userId', '123'); + expect(calledPayload).toHaveProperty('payload.response.statusCode', 200); + expect(calledPayload).toHaveProperty('payload.response.body.message', 'ok'); jest.useRealTimers(); }); }); diff --git a/packages/core/src/libraries/hook.ts b/packages/core/src/libraries/hook.ts index 88b7db0ef..300afa32c 100644 --- a/packages/core/src/libraries/hook.ts +++ b/packages/core/src/libraries/hook.ts @@ -1,14 +1,23 @@ -import { InteractionEvent, userInfoSelectFields } from '@logto/schemas'; +import { generateStandardId } from '@logto/core-kit'; +import { InteractionEvent, LogResult, userInfoSelectFields } from '@logto/schemas'; import { HookEventPayload, HookEvent } from '@logto/schemas/models'; import { trySafe } from '@logto/shared'; import { conditional, pick } from '@silverhand/essentials'; -import { got } from 'got'; +import type { Response } from 'got'; +import { got, HTTPError } from 'got'; import type { Provider } from 'oidc-provider'; +import { LogEntry } from '#src/middleware/koa-audit-log.js'; import modelRouters from '#src/model-routers/index.js'; import { findApplicationById } from '#src/queries/application.js'; +import { insertLog } from '#src/queries/log.js'; import { findUserById } from '#src/queries/user.js'; -import { getInteractionStorage } from '#src/routes/interaction/utils/interaction.js'; + +const parseResponse = ({ statusCode, body }: Response) => ({ + statusCode, + // eslint-disable-next-line no-restricted-syntax + body: trySafe(() => JSON.parse(String(body)) as unknown) ?? String(body), +}); const eventToHook: Record = { [InteractionEvent.Register]: HookEvent.PostRegister, @@ -19,6 +28,7 @@ const eventToHook: Record = { export type Interaction = Awaited>; export const triggerInteractionHooksIfNeeded = async ( + event: InteractionEvent, details?: Interaction, userAgent?: string ) => { @@ -30,9 +40,6 @@ export const triggerInteractionHooksIfNeeded = async ( return; } - const interactionPayload = getInteractionStorage(details.result); - const { event } = interactionPayload; - const hookEvent = eventToHook[event]; const { rows } = await modelRouters.hook.client.readAll(); @@ -58,7 +65,13 @@ export const triggerInteractionHooksIfNeeded = async ( rows .filter(({ event }) => event === hookEvent) .map(async ({ config: { url, headers, retries }, id }) => { + console.log(`\tTriggering hook ${id} due to ${hookEvent} event`); const json: HookEventPayload = { hookId: id, ...payload }; + const logEntry = new LogEntry(`TriggerHook.${hookEvent}`); + + logEntry.append({ json, hookId: id }); + + // Trigger web hook and log response await got .post(url, { headers: { 'user-agent': 'Logto (https://logto.io)', ...headers }, @@ -66,7 +79,28 @@ export const triggerInteractionHooksIfNeeded = async ( retry: { limit: retries }, timeout: { request: 10_000 }, }) - .json(); + .then(async (response) => { + logEntry.append({ + response: parseResponse(response), + }); + }) + .catch(async (error) => { + logEntry.append({ + result: LogResult.Error, + response: conditional(error instanceof HTTPError && parseResponse(error.response)), + error: conditional(error instanceof Error && String(error)), + }); + }); + + console.log( + `\tHook ${id} ${logEntry.payload.result === LogResult.Success ? 'succeeded' : 'failed'}` + ); + + await insertLog({ + id: generateStandardId(), + key: logEntry.key, + payload: logEntry.payload, + }); }) ); }; diff --git a/packages/core/src/middleware/koa-audit-log.test.ts b/packages/core/src/middleware/koa-audit-log.test.ts index 982c50cd9..ca9bcf577 100644 --- a/packages/core/src/middleware/koa-audit-log.test.ts +++ b/packages/core/src/middleware/koa-audit-log.test.ts @@ -10,14 +10,14 @@ import type { WithLogContext, LogPayload } from './koa-audit-log.js'; const { jest } = import.meta; -const nanoIdMock = 'mockId'; - const { insertLog } = mockEsm('#src/queries/log.js', () => ({ insertLog: jest.fn(), })); -mockEsm('nanoid', () => ({ - nanoid: () => nanoIdMock, +// TODO: @Gao fix `mockEsm()` import issue +const nanoIdMock = 'mockId'; +jest.unstable_mockModule('@logto/core-kit', () => ({ + generateStandardId: () => nanoIdMock, })); const koaLog = await pickDefault(import('./koa-audit-log.js')); diff --git a/packages/core/src/middleware/koa-audit-log.ts b/packages/core/src/middleware/koa-audit-log.ts index 75ba0ae48..2aefbe797 100644 --- a/packages/core/src/middleware/koa-audit-log.ts +++ b/packages/core/src/middleware/koa-audit-log.ts @@ -1,9 +1,9 @@ +import { generateStandardId } from '@logto/core-kit'; import type { LogContextPayload, LogKey } from '@logto/schemas'; import { LogResult } from '@logto/schemas'; import { pick } from '@silverhand/essentials'; import type { MiddlewareType } from 'koa'; import type { IRouterParamContext } from 'koa-router'; -import { nanoid } from 'nanoid'; import RequestError from '#src/errors/RequestError/index.js'; import { insertLog } from '#src/queries/log.js'; @@ -138,7 +138,7 @@ export default function koaAuditLog< await Promise.all( entries.map(async ({ payload }) => { return insertLog({ - id: nanoid(), + id: generateStandardId(), key: payload.key, payload: { ip, userAgent, ...payload }, }); diff --git a/packages/core/src/routes/interaction/index.test.ts b/packages/core/src/routes/interaction/index.test.ts index 2ab79db76..7aaa57e6e 100644 --- a/packages/core/src/routes/interaction/index.test.ts +++ b/packages/core/src/routes/interaction/index.test.ts @@ -92,15 +92,17 @@ const { sendPasscodeToIdentifier } = await mockEsmWithActual( const { createLog, prependAllLogEntries } = createMockLogContext(); -mockEsmDefault( +await mockEsmWithActual( '#src/middleware/koa-audit-log.js', - // eslint-disable-next-line unicorn/consistent-function-scoping - (): typeof koaAuditLog => () => async (ctx, next) => { - ctx.createLog = createLog; - ctx.prependAllLogEntries = prependAllLogEntries; + (): { default: typeof koaAuditLog } => ({ + // eslint-disable-next-line unicorn/consistent-function-scoping + default: () => async (ctx, next) => { + ctx.createLog = createLog; + ctx.prependAllLogEntries = prependAllLogEntries; - return next(); - } + return next(); + }, + }) ); const { @@ -272,7 +274,7 @@ describe('session -> interactionRoutes', () => { }); it('should not call validateMandatoryUserProfile for forgot password request', async () => { - getInteractionStorage.mockReturnValueOnce({ + getInteractionStorage.mockReturnValue({ event: InteractionEvent.ForgotPassword, }); diff --git a/packages/core/src/routes/interaction/index.ts b/packages/core/src/routes/interaction/index.ts index e90a47c86..4a20d5d6b 100644 --- a/packages/core/src/routes/interaction/index.ts +++ b/packages/core/src/routes/interaction/index.ts @@ -214,11 +214,10 @@ export default function interactionRoutes( router.post( `${interactionPrefix}/submit`, koaInteractionSie(), - koaInteractionHooks(), + koaInteractionHooks(provider), async (ctx, next) => { const { interactionDetails } = ctx; const interactionStorage = getInteractionStorage(interactionDetails.result); - const { event } = interactionStorage; const accountVerifiedInteraction = await verifyIdentifier(ctx, provider, interactionStorage); diff --git a/packages/core/src/routes/interaction/middleware/koa-interaction-hooks.ts b/packages/core/src/routes/interaction/middleware/koa-interaction-hooks.ts index 4cac93580..54587d2d4 100644 --- a/packages/core/src/routes/interaction/middleware/koa-interaction-hooks.ts +++ b/packages/core/src/routes/interaction/middleware/koa-interaction-hooks.ts @@ -1,18 +1,26 @@ +import { trySafe } from '@logto/shared'; import type { MiddlewareType } from 'koa'; import type { IRouterParamContext } from 'koa-router'; +import type { Provider } from 'oidc-provider'; import { triggerInteractionHooksIfNeeded } from '#src/libraries/hook.js'; +import { getInteractionStorage } from '../utils/interaction.js'; import type { WithInteractionDetailsContext } from './koa-interaction-details.js'; export default function koaInteractionHooks< StateT, ContextT extends WithInteractionDetailsContext, ResponseT ->(): MiddlewareType { +>(provider: Provider): MiddlewareType { return async (ctx, next) => { + const { event } = getInteractionStorage(ctx.interactionDetails.result); + await next(); - void triggerInteractionHooksIfNeeded(ctx.interactionDetails, ctx.header['user-agent']); + // Get up-to-date interaction details + const details = await trySafe(provider.interactionDetails(ctx.req, ctx.res)); + // Hooks should not crash the app + void trySafe(triggerInteractionHooksIfNeeded(event, details, ctx.header['user-agent'])); }; } diff --git a/packages/integration-tests/jest.setup.js b/packages/integration-tests/jest.setup.js index f60a41079..ac2df4e12 100644 --- a/packages/integration-tests/jest.setup.js +++ b/packages/integration-tests/jest.setup.js @@ -16,4 +16,4 @@ global.TextDecoder = TextDecoder; global.TextEncoder = TextEncoder; /* eslint-enable @silverhand/fp/no-mutation */ -jest.setTimeout(10_000); +jest.setTimeout(15_000); diff --git a/packages/integration-tests/src/helpers.ts b/packages/integration-tests/src/helpers.ts index b2017e21f..81f5bcbfb 100644 --- a/packages/integration-tests/src/helpers.ts +++ b/packages/integration-tests/src/helpers.ts @@ -1,4 +1,5 @@ import fs from 'fs/promises'; +import { createServer } from 'http'; import path from 'path'; import type { User, SignIn, SignInIdentifier } from '@logto/schemas'; @@ -188,3 +189,26 @@ export const expectRequestError = (error: unknown, code: string, messageIncludes expect(body.message.includes(messageIncludes)).toBeTruthy(); } }; + +export const createMockServer = (port: number) => { + const server = createServer((request, response) => { + // eslint-disable-next-line @silverhand/fp/no-mutation + response.statusCode = 204; + response.end(); + }); + + return { + listen: async () => + new Promise((resolve) => { + server.listen(port, () => { + resolve(true); + }); + }), + close: async () => + new Promise((resolve) => { + server.close(() => { + resolve(true); + }); + }), + }; +}; diff --git a/packages/integration-tests/src/tests/api/audit-logs/index.test.ts b/packages/integration-tests/src/tests/api/audit-logs/index.test.ts index 38c987d62..350bc2d90 100644 --- a/packages/integration-tests/src/tests/api/audit-logs/index.test.ts +++ b/packages/integration-tests/src/tests/api/audit-logs/index.test.ts @@ -28,7 +28,7 @@ describe('audit logs for interaction', () => { // Expect interaction create log const createLogs = await getLogs( - new URLSearchParams({ logType: `${interaction.prefix}.${interaction.Action.Create}` }) + new URLSearchParams({ logKey: `${interaction.prefix}.${interaction.Action.Create}` }) ); expect(createLogs.some((value) => value.payload.interactionId === interactionId)).toBeTruthy(); @@ -45,7 +45,7 @@ describe('audit logs for interaction', () => { // Expect interaction end log const endLogs = await getLogs( - new URLSearchParams({ logType: `${interaction.prefix}.${interaction.Action.End}` }) + new URLSearchParams({ logKey: `${interaction.prefix}.${interaction.Action.End}` }) ); expect(endLogs.some((value) => value.payload.interactionId === interactionId)).toBeTruthy(); diff --git a/packages/integration-tests/src/tests/api/hooks.test.ts b/packages/integration-tests/src/tests/api/hooks.test.ts index 01158d289..787f6f466 100644 --- a/packages/integration-tests/src/tests/api/hooks.test.ts +++ b/packages/integration-tests/src/tests/api/hooks.test.ts @@ -1,20 +1,46 @@ +import type { LogKey } from '@logto/schemas'; +import { SignInIdentifier, LogResult, InteractionEvent } from '@logto/schemas'; import type { Hooks } from '@logto/schemas/models'; +import { HookEvent } from '@logto/schemas/models'; import type { InferModelType } from '@withtyped/server'; -import { authedAdminApi } from '#src/api/index.js'; +import { authedAdminApi, deleteUser, getLogs, putInteraction } from '#src/api/index.js'; +import { createMockServer } from '#src/helpers.js'; +import { waitFor } from '#src/utils.js'; + +import { initClient, processSession } from './interaction/utils/client.js'; +import { enableAllPasswordSignInMethods } from './interaction/utils/sign-in-experience.js'; +import { generateNewUser, generateNewUserProfile } from './interaction/utils/user.js'; + +type Hook = InferModelType; + +const createPayload = (event: HookEvent, url = 'not_work_url'): Partial => ({ + event, + config: { + url, + headers: { foo: 'bar' }, + retries: 3, + }, +}); describe('hooks', () => { - it('should be able to create, query, and delete a hook', async () => { - type Hook = InferModelType; + const { listen, close } = createMockServer(9999); - const payload = { - event: 'PostRegister', - config: { - url: 'https://foo.bar', - headers: { foo: 'bar' }, - retries: 3, - }, - }; + beforeAll(async () => { + await enableAllPasswordSignInMethods({ + identifiers: [SignInIdentifier.Username], + password: true, + verify: false, + }); + await listen(); + }); + + afterAll(async () => { + await close(); + }); + + it('should be able to create, query, and delete a hook', async () => { + const payload = createPayload(HookEvent.PostRegister); const created = await authedAdminApi.post('hooks', { json: payload }).json(); expect(payload.event).toEqual(created.event); @@ -28,4 +54,87 @@ describe('hooks', () => { 404 ); }); + + it('should trigger sign-in hook and record error when interaction finished', async () => { + const createdHook = await authedAdminApi + .post('hooks', { json: createPayload(HookEvent.PostSignIn) }) + .json(); + const logKey: LogKey = 'TriggerHook.PostSignIn'; + + // Init session and submit + const { + userProfile: { username, password }, + user, + } = await generateNewUser({ username: true, password: true }); + const client = await initClient(); + await client.successSend(putInteraction, { + event: InteractionEvent.SignIn, + identifier: { + username, + password, + }, + }); + await client.submitInteraction(); + await waitFor(500); // Wait for hooks execution + + // Check hook trigger log + const logs = await getLogs(new URLSearchParams({ logKey, page_size: '100' })); + expect( + logs.some( + ({ payload: { hookId, result, error } }) => + hookId === createdHook.id && + result === LogResult.Error && + error === 'RequestError: Invalid URL' + ) + ).toBeTruthy(); + + // Clean up + await authedAdminApi.delete(`hooks/${createdHook.id}`); + await deleteUser(user.id); + }); + + it('should trigger multiple register hooks and record properly when interaction finished', async () => { + const [hook1, hook2] = await Promise.all([ + authedAdminApi.post('hooks', { json: createPayload(HookEvent.PostRegister) }).json(), + authedAdminApi + .post('hooks', { json: createPayload(HookEvent.PostRegister, 'http://localhost:9999') }) + .json(), + ]); + const logKey: LogKey = 'TriggerHook.PostRegister'; + + // Init session and submit + const { username, password } = generateNewUserProfile({ username: true, password: true }); + const client = await initClient(); + await client.send(putInteraction, { + event: InteractionEvent.Register, + profile: { + username, + password, + }, + }); + const { redirectTo } = await client.submitInteraction(); + const id = await processSession(client, redirectTo); + await waitFor(500); // Wait for hooks execution + + // Check hook trigger log + const logs = await getLogs(new URLSearchParams({ logKey, page_size: '100' })); + expect( + logs.some( + ({ payload: { hookId, result, error } }) => + hookId === hook1.id && result === LogResult.Error && error === 'RequestError: Invalid URL' + ) + ).toBeTruthy(); + expect( + logs.some( + ({ payload: { hookId, result } }) => hookId === hook2.id && result === LogResult.Success + ) + ).toBeTruthy(); + + // Clean up + await Promise.all([ + authedAdminApi.delete(`hooks/${hook1.id}`), + authedAdminApi.delete(`hooks/${hook2.id}`), + ]); + await deleteUser(id); + }); }); diff --git a/packages/integration-tests/src/utils.ts b/packages/integration-tests/src/utils.ts index 5c4bf47ae..c14acebd4 100644 --- a/packages/integration-tests/src/utils.ts +++ b/packages/integration-tests/src/utils.ts @@ -12,3 +12,8 @@ export const generatePhone = () => { return crypto.getRandomValues(array).join(''); }; + +export const waitFor = async (ms: number) => + new Promise((resolve) => { + setTimeout(resolve, ms); + }); diff --git a/packages/shared/src/utils/function.test.ts b/packages/shared/src/utils/function.test.ts new file mode 100644 index 000000000..7ddd797bd --- /dev/null +++ b/packages/shared/src/utils/function.test.ts @@ -0,0 +1,35 @@ +import { trySafe } from './function.js'; + +describe('trySafe()', () => { + it('should directly execute and return if the function is not a Promise', () => { + expect(trySafe(() => 'foo')).toStrictEqual('foo'); + expect( + trySafe(() => { + throw new Error('Test'); + }) + // eslint-disable-next-line unicorn/no-useless-undefined + ).toStrictEqual(undefined); + }); + + it('should execute or unwrap a Promise and catch the error', async () => { + expect( + await trySafe( + new Promise((resolve) => { + setTimeout(() => { + resolve('bar'); + }, 0); + }) + ) + ).toStrictEqual('bar'); + + expect( + await trySafe( + async () => + new Promise((resolve, reject) => { + reject(); + }) + ) + // eslint-disable-next-line unicorn/no-useless-undefined + ).toStrictEqual(undefined); + }); +}); diff --git a/packages/shared/src/utils/function.ts b/packages/shared/src/utils/function.ts index 717194a2f..f55dfb727 100644 --- a/packages/shared/src/utils/function.ts +++ b/packages/shared/src/utils/function.ts @@ -15,9 +15,27 @@ export const tryThat = async ( } }; -export const trySafe = async (exec: Promise | (() => Promise)): Promise => { +export const isPromise = (value: unknown): value is Promise => + value !== null && + (typeof value === 'object' || typeof value === 'function') && + 'then' in value && + typeof value.then === 'function'; + +export type TrySafe = { + (exec: Promise | (() => Promise)): Promise; + (exec: () => T): T | undefined; +}; + +export const trySafe: TrySafe = (exec) => { try { - return await (typeof exec === 'function' ? exec() : exec); + const unwrapped = typeof exec === 'function' ? exec() : exec; + + return isPromise(unwrapped) + ? // eslint-disable-next-line promise/prefer-await-to-then + unwrapped.catch((error: unknown) => { + console.error('trySafe() caught error', error); + }) + : unwrapped; } catch (error: unknown) { console.error('trySafe() caught error', error); }