Merge pull request #2724 from logto-io/gao-hooks-integration-tests

test: add integration tests for interaction hooks

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;
 });

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();
   });
 });

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, HookEvent> = {
   [InteractionEvent.Register]: HookEvent.PostRegister,
@@ -19,6 +28,7 @@ const eventToHook: Record<InteractionEvent, HookEvent> = {
 export type Interaction = Awaited<ReturnType<Provider['interactionDetails']>>;
 
 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,
+        });
       })
   );
 };

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'));

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 },
           });

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,
       });
 

packages/core/src/routes/interaction/index.ts

@@ -214,11 +214,10 @@ export default function interactionRoutes<T extends AnonymousRouter>(
   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);

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<IRouterParamContext>,
   ResponseT
->(): MiddlewareType<StateT, ContextT, ResponseT> {
+>(provider: Provider): MiddlewareType<StateT, ContextT, ResponseT> {
   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']));
   };
 }

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);

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);
+        });
+      }),
+  };
+};

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();
 

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<typeof Hooks>;
+
+const createPayload = (event: HookEvent, url = 'not_work_url'): Partial<Hook> => ({
+  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<typeof Hooks>;
+  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<Hook>();
 
     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<Hook>();
+    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<Hook>(),
+      authedAdminApi
+        .post('hooks', { json: createPayload(HookEvent.PostRegister, 'http://localhost:9999') })
+        .json<Hook>(),
+    ]);
+    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);
+  });
 });

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);
+  });

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);
+  });
+});

packages/shared/src/utils/function.ts

@@ -15,9 +15,27 @@ export const tryThat = async <T, E extends Error>(
   }
 };
 
-export const trySafe = async <T>(exec: Promise<T> | (() => Promise<T>)): Promise<T | undefined> => {
+export const isPromise = (value: unknown): value is Promise<unknown> =>
+  value !== null &&
+  (typeof value === 'object' || typeof value === 'function') &&
+  'then' in value &&
+  typeof value.then === 'function';
+
+export type TrySafe = {
+  <T>(exec: Promise<T> | (() => Promise<T>)): Promise<T | undefined>;
+  <T>(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);
   }