diff --git a/src/index.ts b/src/index.ts index cf5e96d..5a921c3 100644 --- a/src/index.ts +++ b/src/index.ts @@ -58,6 +58,7 @@ export * from './sdk/filters'; export * from './sdk/handlers'; export * from './sdk/loggers'; export * from './sdk/middleware'; +export * from './sdk/StructuredLogger'; export * from './util/EnvoySignatureVerifier'; export * from './util/axiosConstructor'; diff --git a/src/sdk/EnvoyRequest.ts b/src/sdk/EnvoyRequest.ts index 22acf07..37edccf 100644 --- a/src/sdk/EnvoyRequest.ts +++ b/src/sdk/EnvoyRequest.ts @@ -1,6 +1,7 @@ import { Request } from 'express'; import EnvoyPluginSDK from './EnvoyPluginSDK'; import EnvoyMeta, { EnvoyEventMeta, EnvoyRouteMeta } from './EnvoyMeta'; +import { StructuredLogger } from './StructuredLogger'; import EntryPayload from '../payloads/EntryPayload'; import InvitePayload from '../payloads/InvitePayload'; import LocationPayload from '../payloads/LocationPayload'; @@ -37,6 +38,14 @@ export interface VerifiedRequest extends Request { */ export interface EnvoyBaseRequest extends VerifiedRequest { envoy: EnvoyPluginSDK; + /** + * Request-scoped structured logger. Set by `envoyMiddleware` when a + * `loggerFactory` option is provided, or by a downstream middleware that + * attaches a context-enriched child logger. May be absent when the caller + * has not opted into request-scoped logging — narrow with + * {@link isRequestWithLogger} before use. + */ + logger?: StructuredLogger; } /** diff --git a/src/sdk/StructuredLogger.ts b/src/sdk/StructuredLogger.ts new file mode 100644 index 0000000..d5b99f1 --- /dev/null +++ b/src/sdk/StructuredLogger.ts @@ -0,0 +1,102 @@ +import { Request } from 'express'; + +/** + * Minimum contract the SDK requires from a logger attached to a request. + * + * Two methods: + * - `error(...)` — used by `structuredErrorMiddleware` to emit unhandled + * errors as structured log events. + * - `child(context)` — used by `addRequestLoggerContext` so middleware + * downstream from `envoyMiddleware` can enrich the request logger with + * additional context (integration name, install id, route name, …) + * without each middleware re-implementing the "if logger, child; + * else construct" dance. + * + * The `StructuredLogger` from `@envoy/envoy-integrations-internal-sdk` + * already implements both methods, as do most production logging libraries + * (pino, bunyan, winston). Callers are free to attach a logger with extra + * methods (`info`, `warn`, `debug`, …); the SDK just won't call them. + * + * @category Logger + */ +export interface StructuredLogger { + error(message: string, error: Error, metadata?: Record): void; + child(context: Record): StructuredLogger; +} + +/** + * An express `Request` that has been augmented with a `StructuredLogger` at + * `req.logger` — usually by `envoyMiddleware` (when a `loggerFactory` option + * is provided) or by a downstream middleware that wants to attach a + * context-enriched child logger. + * + * @category Logger + */ +export interface RequestWithLogger extends Request { + logger: StructuredLogger; +} + +/** + * Type guard that narrows a request to {@link RequestWithLogger} when a + * usable structured logger is present at `req.logger`. + * + * Verifies *both* `error` and `child` are functions — anything attached as + * `req.logger` must satisfy the full {@link StructuredLogger} contract for + * the SDK helpers to operate on it. + * + * @category Logger + */ +export function isRequestWithLogger(req: Request): req is RequestWithLogger { + const candidate = (req as { logger?: unknown }).logger; + if (typeof candidate !== 'object' || candidate === null) { + return false; + } + const logger = candidate as { error?: unknown; child?: unknown }; + return typeof logger.error === 'function' && typeof logger.child === 'function'; +} + +/** + * Adds context to `req.logger` using the pattern recommended for every + * middleware downstream from `envoyMiddleware`: + * + * - **If `req.logger` is already set**, replace it with + * `req.logger.child(additionalContext)` so subsequent middleware / + * handlers see a logger pre-tagged with the accumulated context. + * - **Otherwise**, if a `fallback` factory is provided, call it to + * construct a logger from scratch. Use this in middleware that wants + * to be usable both with and without `envoyMiddleware`'s loggerFactory + * wired up. + * - **Otherwise**, leave `req.logger` undefined — the caller opted out + * of structured logging. + * + * Exceptions thrown by either `req.logger.child(...)` or the fallback + * factory are caught and surfaced via `console.error` so a buggy logger + * never breaks the request pipeline. The previous `req.logger` is + * preserved in that case. + * + * @category Logger + */ +export function addRequestLoggerContext( + req: Request, + additionalContext: Record, + fallback?: (req: Request, context: Record) => StructuredLogger, +): void { + const reqWithLogger = req as Request & { logger?: StructuredLogger }; + if (isRequestWithLogger(req)) { + try { + reqWithLogger.logger = req.logger.child(additionalContext); + } catch (childErr) { + // eslint-disable-next-line no-console + console.error('addRequestLoggerContext: req.logger.child threw', childErr); + } + return; + } + if (fallback) { + try { + reqWithLogger.logger = fallback(req, additionalContext); + } catch (fallbackErr) { + // eslint-disable-next-line no-console + console.error('addRequestLoggerContext: fallback factory threw', fallbackErr); + } + } +} diff --git a/src/sdk/middleware.ts b/src/sdk/middleware.ts index 00a3365..4326f32 100644 --- a/src/sdk/middleware.ts +++ b/src/sdk/middleware.ts @@ -8,6 +8,196 @@ import EnvoyResponse from './EnvoyResponse'; import EnvoyPluginJobAttachment, { EnvoyPluginScreenerJobAttachment } from './EnvoyPluginJobAttachment'; import EnvoyPluginSDK from './EnvoyPluginSDK'; import EnvoyPluginAPI from './EnvoyPluginAPI'; +import { StructuredLogger, addRequestLoggerContext, isRequestWithLogger } from './StructuredLogger'; + +/** + * Request-scoped context that `envoyMiddleware` makes available to a + * `loggerFactory` so the factory can produce a logger pre-tagged with the + * standard Envoy fields. + * + * Mirrors the `EnvoyLoggingContext` that + * `@envoy/envoy-integrations-internal-sdk` builds via `extractLoggingContext`, + * so a service can swap its bespoke `pluginMiddleware` logger setup for the + * SDK's built-in one without losing any Datadog facets it already indexes + * on (`companyId`, `installId`, `event`, etc.). Every field is optional — + * route requests don't carry `event`/`category`, validation requests have no + * `recordId`/`recordType`, and the `?name=` convention only applies to + * monolith services. + * + * @category Middleware + */ +export interface EnvoyLoggerContext { + /** + * Integration name parsed from the `?name=` query param. + * + * NOTE: this is a convention used by Envoy monolith integration services + * (e.g. `screener-integration-service`, `pacs-integration-service`, + * `access-control-integration-service`) that fan out to plugin-specific + * routes via a single `?name=` dispatcher. Standalone + * single-purpose plugins that don't use the `?name=` query param will + * receive `undefined` here. + */ + integrationName?: string; + /** `req.envoy.meta.company.id` — the Envoy company that originated the request. */ + companyId?: string; + /** `req.envoy.meta.location.id` — the Envoy location the request is scoped to. */ + locationId?: string; + /** `req.envoy.meta.install_id` — the specific plugin installation that fired the request. */ + installId?: string; + /** `req.envoy.payload.id` — the visitor/invite/entry record id (event requests only). */ + recordId?: string; + /** `req.envoy.payload.type` — the JSON:API type of the payload (event requests only). */ + recordType?: string; + /** + * `req.envoy.meta.event` — the Envoy event name (e.g. `entry_sign_in`, + * `invite_created`). Only present on event requests; route requests + * (validation URLs, options URLs, etc.) will have this `undefined`. + */ + event?: string; + /** + * Coarse-grained grouping of `event` (e.g. `Visitor`, `Workplace`, + * `Desks`, `Communication`). Mirrors the category mapping used by + * `extractLoggingContext` in the internal SDK so cross-service Datadog + * dashboards keep working. + */ + category?: string; +} + +/** + * Mirrors the category mapping in + * `@envoy/envoy-integrations-internal-sdk`'s `extractLoggingContext`. Kept + * here so the SDK can populate `EnvoyLoggerContext.category` without taking + * a dependency on the internal SDK (which itself depends on this SDK). + */ +const ENVOY_EVENT_CATEGORIES: Readonly> = { + entry_sign_in: 'Visitor', + entry_sign_out: 'Visitor', + entry_screen_requested: 'Visitor', + entry_screened: 'Visitor', + entry_reviewed: 'Visitor', + entry_manually_updated: 'Visitor', + invite_created: 'Visitor', + invite_updated: 'Visitor', + invite_removed: 'Visitor', + invite_reviewed: 'Visitor', + upcoming_visit: 'Visitor', + invite_screen_requested: 'Visitor', + identity_verification_requested: 'Visitor', + entry_badge_print_requested: 'Visitor', + employee_entry_sign_in: 'Workplace', + employee_entry_sign_out: 'Workplace', + employee_invite_created: 'Workplace', + employee_invite_updated: 'Workplace', + employee_upcoming_visit: 'Workplace', + desk_sign_in: 'Desks', + takeover_started: 'Communication', + takeover_ended: 'Communication', +}; + +/** + * Options for {@link envoyMiddleware}. + * + * Combines the signature-verifier options (which configure how Envoy's HMAC + * header is checked) with an optional `loggerFactory` hook for attaching a + * request-scoped {@link StructuredLogger}. + * + * @category Middleware + */ +export interface EnvoyMiddlewareOptions extends Partial { + /** + * If provided, invoked once per request, synchronously at the top of the + * handler (*before* body parsing and `EnvoyPluginAPI.loginAsPlugin`), to + * build a base {@link StructuredLogger}. The result is attached to + * `req.logger`. + * + * The context only contains `integrationName` — the one field derivable + * from the raw request without parsing the body. Subsequent middleware + * in the chain (`envoyLoggerContextMiddleware`, your own per-service + * middleware, etc.) enriches `req.logger` with additional context via + * {@link addRequestLoggerContext}, which calls `req.logger.child(...)` + * instead of asking the factory to construct a new logger. + * + * This guarantees `req.logger` exists as early as possible so + * body-parser, plugin-login, and `EnvoyPluginSDK` construction errors + * land as structured logs in `structuredErrorMiddleware` rather than as + * unstructured `console.log` output. + * + * Most factories are a one-liner: `(_req, ctx) => rootLogger.child(ctx)`. + * + * Exceptions thrown by the factory are caught and surfaced via + * `console.error` — a buggy factory never breaks the request pipeline. + */ + loggerFactory?: (req: Request, context: EnvoyLoggerContext) => StructuredLogger; +} + +/** + * Pulls the integration name from `req.query.name` if (and only if) it is a + * single string. This matches the dispatch convention used by Envoy monolith + * integration services — see {@link EnvoyLoggerContext.integrationName}. + */ +function extractIntegrationName(req: Request): string | undefined { + const candidate = req.query?.name; + return typeof candidate === 'string' ? candidate : undefined; +} + +/** + * Builds the full {@link EnvoyLoggerContext} from an Envoy request. Defensive + * against missing fields — every property is optional, so a malformed or + * partial request degrades to a logger with whatever context was available + * rather than throwing. + * + * Exported so that downstream middleware (e.g. a service's own + * `pluginMiddleware`) can rebuild the same context when replacing + * `req.logger` with a richer child logger. + * + * @category Middleware + */ +export function extractLoggerContext(req: EnvoyRequest): EnvoyLoggerContext { + const context: EnvoyLoggerContext = { + integrationName: extractIntegrationName(req), + }; + const envoy = req.envoy as EnvoyPluginSDK | undefined; + if (!envoy) { + return context; + } + // `meta` and `payload` are typed against generics on EnvoyPluginSDK; we treat them + // as the structural minimum we need here so this stays useful for every request + // shape (event, route, validation, etc.). Access is wrapped in try/catch because + // EnvoyPluginSDK's getters throw on unverified requests — a bad signature should + // not cascade into lost log context. + let meta: + | Partial<{ + install_id: string; + location: { id?: string }; + company: { id?: string }; + event: string; + }> + | undefined; + let payload: Partial<{ id: string; type: string }> | undefined; + try { + meta = envoy.meta as typeof meta; + } catch { + // unverified or missing meta — leave undefined + } + try { + payload = envoy.payload as typeof payload; + } catch { + // unverified or missing payload — leave undefined + } + + context.installId = meta?.install_id; + context.locationId = meta?.location?.id; + context.companyId = meta?.company?.id; + context.recordId = payload?.id; + context.recordType = payload?.type; + + if (meta && 'event' in meta && typeof meta.event === 'string') { + context.event = meta.event; + context.category = ENVOY_EVENT_CATEGORIES[meta.event] ?? 'Unrecognized'; + } + + return context; +} /** * Sets up an {@link EnvoyPluginSDK} object in the path `req.envoy`. @@ -16,10 +206,19 @@ import EnvoyPluginAPI from './EnvoyPluginAPI'; * Also verifies that the request is coming from Envoy, * as well as managing the plugin access token lifecycle. * + * If a `loggerFactory` is supplied, attaches the produced + * {@link StructuredLogger} to `req.logger` synchronously at the start of + * the handler with an `integrationName`-only context. Downstream + * middleware adds the rest of the Envoy facets (`companyId`, `installId`, + * `event`, `category`, …) via {@link addRequestLoggerContext} — call + * {@link envoyLoggerContextMiddleware} for the standard enrichment, or use + * the helper directly in your own middleware. + * * @category Middleware */ -export function envoyMiddleware(options?: EnvoySignatureVerifierOptions): RequestHandler { - const signatureVerifier = new EnvoySignatureVerifier(options); +export function envoyMiddleware(options?: EnvoyMiddlewareOptions): RequestHandler { + const { loggerFactory, ...verifierOptions } = options ?? {}; + const signatureVerifier = new EnvoySignatureVerifier(verifierOptions as EnvoySignatureVerifierOptions); const verify = (req: VerifiedRequest, res: Response, rawBody: Buffer) => { req[VERIFIED] = signatureVerifier.verify(req, rawBody); }; @@ -28,6 +227,21 @@ export function envoyMiddleware(options?: EnvoySignatureVerifierOptions): Reques let threshold = 0; return (req: Request, res: Response, next: NextFunction) => { + // Attach a base logger via the factory synchronously. `integrationName` + // is the only context derivable from the raw request before body + // parsing — every downstream middleware extends this base via + // `addRequestLoggerContext` rather than calling the factory again. + if (loggerFactory) { + try { + const baseContext: EnvoyLoggerContext = { integrationName: extractIntegrationName(req) }; + (req as Request & { logger?: StructuredLogger }).logger = loggerFactory(req, baseContext); + } catch (factoryErr) { + // A failing loggerFactory must not break the request pipeline — surface + // the error so it's debuggable, then continue without a request logger. + // eslint-disable-next-line no-console + console.error('envoyMiddleware: loggerFactory threw', factoryErr); + } + } json(req, res, async (err) => { if (err) { return next(err); @@ -98,6 +312,56 @@ export function envoyMiddleware(options?: EnvoySignatureVerifierOptions): Reques }; } +/** + * Options for {@link envoyLoggerContextMiddleware}. + * + * @category Middleware + */ +export interface EnvoyLoggerContextMiddlewareOptions { + /** + * If `req.logger` isn't already set (the caller didn't wire + * `envoyMiddleware`'s `loggerFactory`), this factory is used to + * construct one from scratch with the Envoy context. Omit to make this + * middleware a no-op when no upstream logger exists. + */ + fallback?: (req: Request, context: EnvoyLoggerContext) => StructuredLogger; +} + +/** + * Enriches `req.logger` with the standard Envoy logging facets (extracted + * via {@link extractLoggerContext}) using {@link addRequestLoggerContext}. + * Place this after `envoyMiddleware` so `req.envoy` is initialized. + * + * Behavior follows the convention recommended for every middleware + * downstream from `envoyMiddleware`: + * + * - If `req.logger` is set, it's replaced with + * `req.logger.child({ companyId, installId, event, … })`. + * - Otherwise, if a `fallback` factory is provided, it's used to + * construct a logger from scratch. + * - Otherwise, this middleware is a no-op. + * + * Your own per-service middleware can use the same pattern via + * {@link addRequestLoggerContext} to layer in additional context (route + * name, validation step, plugin name, …). + * + * @category Middleware + */ +export function envoyLoggerContextMiddleware(options?: EnvoyLoggerContextMiddlewareOptions): RequestHandler { + const { fallback } = options ?? {}; + // Adapt the typed `fallback(req, EnvoyLoggerContext)` into the generic + // `(req, Record)` shape that addRequestLoggerContext + // expects. `extractLoggerContext` only emits keys from EnvoyLoggerContext + // so the cast back to that type is safe. + const fallbackAdapter = fallback + ? (req: Request, context: Record) => fallback(req, context as EnvoyLoggerContext) + : undefined; + return (req: Request, _res: Response, next: NextFunction) => { + addRequestLoggerContext(req, { ...extractLoggerContext(req as EnvoyRequest) }, fallbackAdapter); + next(); + }; +} + /** * Catches errors and sets the proper status code. * @@ -114,3 +378,62 @@ export function errorMiddleware(onError: (err: Error) => void = () => {}): Error res.end(JSON.stringify({ message: err.message })); }; } + +/** + * Like {@link errorMiddleware} but emits errors as structured log events + * instead of stringifying via a side-effect callback. + * + * Default behavior (when no `onError` callback is supplied): + * - If upstream middleware has attached a {@link StructuredLogger} at + * `req.logger` (typically via `envoyMiddleware`'s `loggerFactory` + * option), calls `req.logger.error(message, err, metadata)`. The + * metadata includes `operation`, `httpMethod`, and `httpUrl` so Datadog + * (or any structured log store) can index on them. + * - Otherwise, falls back to `console.error(err)` so errors are never + * silently lost. + * + * Pass an `onError` callback to take full control of how the error is logged + * — the SDK invokes it with both the error and the request, so callers can + * extract request-scoped context however they like. + * + * Named separately from `errorMiddleware` so existing consumers that switch + * over without first wiring `req.logger` upstream don't silently lose the + * structured payload — the fallback `console.error` makes that scenario + * observable instead of silent. + * + * @category Middleware + */ +export function structuredErrorMiddleware(onError?: (err: Error, req: Request) => void): ErrorRequestHandler { + return (err: Error, req: Request, res: Response, next: NextFunction): void => { + if (onError) { + try { + onError(err, req); + } catch (cbErr) { + // Don't let a logging callback failure swallow the original error. + // eslint-disable-next-line no-console + console.error('structuredErrorMiddleware: onError callback threw', cbErr); + } + } else if (isRequestWithLogger(req)) { + try { + req.logger.error('Unhandled error in request pipeline', err, { + operation: 'structuredErrorMiddleware', + httpMethod: req.method, + httpUrl: req.originalUrl, + }); + } catch (logErr) { + // eslint-disable-next-line no-console + console.error('structuredErrorMiddleware: req.logger.error threw', logErr); + } + } else { + // No request-scoped logger attached — surface the raw error so it isn't lost. + // eslint-disable-next-line no-console + console.error(err); + } + if (res.headersSent) { + return next(err); + } + res.statusCode = HttpStatus.UNEXPECTED_FAILURE; + res.setHeader('Content-Type', 'application/json'); + res.end(JSON.stringify({ message: err.message })); + }; +} diff --git a/test/sdk/StructuredLogger.test.ts b/test/sdk/StructuredLogger.test.ts new file mode 100644 index 0000000..6baf1bc --- /dev/null +++ b/test/sdk/StructuredLogger.test.ts @@ -0,0 +1,130 @@ +import type { Request } from 'express'; + +import { addRequestLoggerContext, isRequestWithLogger, StructuredLogger } from '../../src/sdk/StructuredLogger'; + +function reqWith(logger: unknown): Request { + return { logger } as unknown as Request; +} + +function makeLogger(): StructuredLogger { + // Implements the full contract: `error` and `child`. `child` returns + // a fresh logger that also implements the contract, so chained calls + // are well-typed. + return { + error: jest.fn(), + child: jest.fn(() => makeLogger()), + }; +} + +describe('isRequestWithLogger', () => { + it('narrows when req.logger has callable error AND child methods', () => { + const req = reqWith(makeLogger()); + + expect(isRequestWithLogger(req)).toBe(true); + + if (isRequestWithLogger(req)) { + // Type guard narrows `req` to RequestWithLogger so this access is well-typed. + expect(typeof req.logger.error).toBe('function'); + expect(typeof req.logger.child).toBe('function'); + } + }); + + it('returns false when req.logger is missing', () => { + expect(isRequestWithLogger({} as Request)).toBe(false); + }); + + it('returns false when req.logger is null', () => { + expect(isRequestWithLogger(reqWith(null))).toBe(false); + }); + + it('returns false when req.logger is a non-object', () => { + expect(isRequestWithLogger(reqWith('string-logger'))).toBe(false); + expect(isRequestWithLogger(reqWith(42))).toBe(false); + }); + + it('returns false when req.logger.error is not a function', () => { + expect(isRequestWithLogger(reqWith({ error: 'not a fn', child: jest.fn() }))).toBe(false); + expect(isRequestWithLogger(reqWith({ info: jest.fn(), child: jest.fn() }))).toBe(false); + }); + + it('returns false when req.logger.child is not a function', () => { + // Loggers must support .child() so downstream middleware can layer in + // context — a logger without .child can't participate in the contract. + expect(isRequestWithLogger(reqWith({ error: jest.fn() }))).toBe(false); + expect(isRequestWithLogger(reqWith({ error: jest.fn(), child: 'not a fn' }))).toBe(false); + }); +}); + +describe('addRequestLoggerContext', () => { + /* eslint-disable no-console */ + const originalConsoleError = console.error; + let consoleErrorSpy: jest.Mock; + + beforeEach(() => { + consoleErrorSpy = jest.fn(); + console.error = consoleErrorSpy; + }); + + afterEach(() => { + console.error = originalConsoleError; + }); + /* eslint-enable no-console */ + + it('replaces req.logger with the child logger when one is already present', () => { + const childLogger = makeLogger(); + const baseLogger = { error: jest.fn(), child: jest.fn(() => childLogger) }; + const req = reqWith(baseLogger); + + addRequestLoggerContext(req, { installId: 'i-1' }); + + expect(baseLogger.child).toHaveBeenCalledWith({ installId: 'i-1' }); + expect((req as Request & { logger?: unknown }).logger).toBe(childLogger); + }); + + it('uses the fallback factory when req.logger is absent', () => { + const constructed = makeLogger(); + const fallback = jest.fn(() => constructed); + const req = {} as Request; + + addRequestLoggerContext(req, { integrationName: 'checkr' }, fallback); + + expect(fallback).toHaveBeenCalledWith(req, { integrationName: 'checkr' }); + expect((req as Request & { logger?: unknown }).logger).toBe(constructed); + }); + + it('is a no-op when req.logger is absent and no fallback is provided', () => { + const req = {} as Request; + + addRequestLoggerContext(req, { installId: 'i-1' }); + + expect((req as Request & { logger?: unknown }).logger).toBeUndefined(); + }); + + it('catches exceptions thrown by req.logger.child and keeps the previous logger', () => { + const baseLogger = { + error: jest.fn(), + child: jest.fn(() => { + throw new Error('child blew up'); + }), + }; + const req = reqWith(baseLogger); + + addRequestLoggerContext(req, { installId: 'i-1' }); + + expect(consoleErrorSpy).toHaveBeenCalledWith('addRequestLoggerContext: req.logger.child threw', expect.any(Error)); + // Previous logger preserved — never downgrades. + expect((req as Request & { logger?: unknown }).logger).toBe(baseLogger); + }); + + it('catches exceptions thrown by the fallback factory', () => { + const fallback = jest.fn(() => { + throw new Error('fallback blew up'); + }); + const req = {} as Request; + + addRequestLoggerContext(req, { installId: 'i-1' }, fallback); + + expect(consoleErrorSpy).toHaveBeenCalledWith('addRequestLoggerContext: fallback factory threw', expect.any(Error)); + expect((req as Request & { logger?: unknown }).logger).toBeUndefined(); + }); +}); diff --git a/test/sdk/middleware.test.ts b/test/sdk/middleware.test.ts new file mode 100644 index 0000000..d471f95 --- /dev/null +++ b/test/sdk/middleware.test.ts @@ -0,0 +1,511 @@ +import type { NextFunction, Request, Response } from 'express'; + +import EnvoyPluginAPI from '../../src/sdk/EnvoyPluginAPI'; +import EnvoyRequest, { VERIFIED } from '../../src/sdk/EnvoyRequest'; +import { + envoyLoggerContextMiddleware, + envoyMiddleware, + extractLoggerContext, + structuredErrorMiddleware, +} from '../../src/sdk/middleware'; +import { StructuredLogger } from '../../src/sdk/StructuredLogger'; + +type MockResponse = { + headersSent: boolean; + statusCode: number; + setHeader: jest.Mock; + end: jest.Mock; +}; + +/** + * A test logger that satisfies the full {@link StructuredLogger} contract: + * `error` records calls; `child(ctx)` returns a new test logger that records + * the context it was built with, so multi-step enrichment chains can be + * inspected. + */ +function buildLogger(): StructuredLogger & { error: jest.Mock; child: jest.Mock } { + const logger = { + error: jest.fn(), + // `child` is set after construction so the recursive type lines up. + child: jest.fn(), + }; + logger.child.mockImplementation(() => buildLogger()); + return logger; +} + +function buildReq(overrides: Partial = {}): Request { + return { + method: 'POST', + originalUrl: '/some/path', + headers: {}, + ...overrides, + } as Request; +} + +function buildRes(headersSent = false): MockResponse { + return { + headersSent, + statusCode: 0, + setHeader: jest.fn(), + end: jest.fn(), + }; +} + +describe('structuredErrorMiddleware', () => { + /* eslint-disable no-console */ + const originalConsoleError = console.error; + let consoleErrorSpy: jest.Mock; + + beforeEach(() => { + consoleErrorSpy = jest.fn(); + console.error = consoleErrorSpy; + }); + + afterEach(() => { + console.error = originalConsoleError; + }); + /* eslint-enable no-console */ + + describe('default behavior (no onError callback)', () => { + it('calls req.logger.error with message, err, and {operation, httpMethod, httpUrl}', () => { + const logger = buildLogger(); + const req = buildReq({ logger }); + const res = buildRes(); + const next = jest.fn() as unknown as NextFunction; + const err = new Error('boom'); + + structuredErrorMiddleware()(err, req, res as unknown as Response, next); + + expect(logger.error).toHaveBeenCalledTimes(1); + expect(logger.error).toHaveBeenCalledWith('Unhandled error in request pipeline', err, { + operation: 'structuredErrorMiddleware', + httpMethod: 'POST', + httpUrl: '/some/path', + }); + expect(consoleErrorSpy).not.toHaveBeenCalled(); + }); + + it('falls back to console.error when req.logger is missing', () => { + const req = buildReq(); + const res = buildRes(); + const next = jest.fn() as unknown as NextFunction; + const err = new Error('boom'); + + structuredErrorMiddleware()(err, req, res as unknown as Response, next); + + expect(consoleErrorSpy).toHaveBeenCalledTimes(1); + expect(consoleErrorSpy).toHaveBeenCalledWith(err); + }); + + it('falls back to console.error when req.logger has no error method', () => { + const req = buildReq({ logger: { info: jest.fn(), child: jest.fn() } }); + const res = buildRes(); + const next = jest.fn() as unknown as NextFunction; + const err = new Error('boom'); + + structuredErrorMiddleware()(err, req, res as unknown as Response, next); + + expect(consoleErrorSpy).toHaveBeenCalledTimes(1); + expect(consoleErrorSpy).toHaveBeenCalledWith(err); + }); + + it('falls back to console.error when req.logger has no child method', () => { + // .child is required by the StructuredLogger contract — without it the + // logger can't participate in the addRequestLoggerContext pattern. + const req = buildReq({ logger: { error: jest.fn() } }); + const res = buildRes(); + const next = jest.fn() as unknown as NextFunction; + const err = new Error('boom'); + + structuredErrorMiddleware()(err, req, res as unknown as Response, next); + + expect(consoleErrorSpy).toHaveBeenCalledTimes(1); + expect(consoleErrorSpy).toHaveBeenCalledWith(err); + }); + + it('falls back to console.error when req.logger is null', () => { + const req = buildReq({ logger: null }); + const res = buildRes(); + const next = jest.fn() as unknown as NextFunction; + const err = new Error('boom'); + + structuredErrorMiddleware()(err, req, res as unknown as Response, next); + + expect(consoleErrorSpy).toHaveBeenCalledTimes(1); + expect(consoleErrorSpy).toHaveBeenCalledWith(err); + }); + + it('does not propagate exceptions thrown by req.logger.error', () => { + const logger = buildLogger(); + logger.error.mockImplementation(() => { + throw new Error('logger blew up'); + }); + const req = buildReq({ logger }); + const res = buildRes(); + const next = jest.fn() as unknown as NextFunction; + const err = new Error('boom'); + + expect(() => { + structuredErrorMiddleware()(err, req, res as unknown as Response, next); + }).not.toThrow(); + + expect(logger.error).toHaveBeenCalled(); + expect(consoleErrorSpy).toHaveBeenCalledWith( + 'structuredErrorMiddleware: req.logger.error threw', + expect.any(Error), + ); + }); + }); + + describe('with onError callback', () => { + it('invokes the callback with (err, req) and does not touch req.logger', () => { + const onError = jest.fn(); + const logger = buildLogger(); + const req = buildReq({ logger }); + const res = buildRes(); + const next = jest.fn() as unknown as NextFunction; + const err = new Error('boom'); + + structuredErrorMiddleware(onError)(err, req, res as unknown as Response, next); + + expect(onError).toHaveBeenCalledTimes(1); + expect(onError).toHaveBeenCalledWith(err, req); + expect(logger.error).not.toHaveBeenCalled(); + }); + + it('does not propagate exceptions thrown by the callback', () => { + const onError = jest.fn(() => { + throw new Error('callback blew up'); + }); + const req = buildReq(); + const res = buildRes(); + const next = jest.fn() as unknown as NextFunction; + const err = new Error('boom'); + + expect(() => { + structuredErrorMiddleware(onError)(err, req, res as unknown as Response, next); + }).not.toThrow(); + expect(consoleErrorSpy).toHaveBeenCalledWith( + 'structuredErrorMiddleware: onError callback threw', + expect.any(Error), + ); + }); + }); + + describe('response handling', () => { + it('sends a 500 JSON response when headers have not been sent', () => { + const req = buildReq(); + const res = buildRes(); + const next = jest.fn() as unknown as NextFunction; + const err = new Error('boom'); + + structuredErrorMiddleware()(err, req, res as unknown as Response, next); + + expect(res.statusCode).toBe(500); + expect(res.setHeader).toHaveBeenCalledWith('Content-Type', 'application/json'); + expect(res.end).toHaveBeenCalledWith(JSON.stringify({ message: 'boom' })); + expect(next).not.toHaveBeenCalled(); + }); + + it('delegates to next(err) when headers have already been sent', () => { + const req = buildReq(); + const res = buildRes(true); + const next = jest.fn(); + const err = new Error('boom'); + + structuredErrorMiddleware()(err, req, res as unknown as Response, next as unknown as NextFunction); + + expect(next).toHaveBeenCalledWith(err); + expect(res.end).not.toHaveBeenCalled(); + }); + }); +}); + +describe('envoyMiddleware loggerFactory', () => { + /* eslint-disable no-console */ + const originalConsoleError = console.error; + let consoleErrorSpy: jest.Mock; + + beforeEach(() => { + consoleErrorSpy = jest.fn(); + console.error = consoleErrorSpy; + }); + + afterEach(() => { + console.error = originalConsoleError; + }); + /* eslint-enable no-console */ + + it('attaches a logger synchronously with integrationName-only context, before body parsing', () => { + const logger = buildLogger(); + const loggerFactory = jest.fn(() => logger); + const middleware = envoyMiddleware({ + secret: 'test-secret', + algorithm: 'sha256', + encoding: 'base64', + header: 'x-envoy-signature', + loggerFactory, + }); + + const req = buildReq({ query: { name: 'checkr' } }); + middleware(req, buildRes() as unknown as Response, jest.fn() as unknown as NextFunction); + + expect(loggerFactory).toHaveBeenCalledTimes(1); + expect(loggerFactory).toHaveBeenCalledWith(req, { integrationName: 'checkr' }); + expect((req as Request & { logger?: unknown }).logger).toBe(logger); + }); + + it('leaves req.logger unset (and console.errors) when the factory throws', () => { + const middleware = envoyMiddleware({ + secret: 'test-secret', + algorithm: 'sha256', + encoding: 'base64', + header: 'x-envoy-signature', + loggerFactory: () => { + throw new Error('factory blew up'); + }, + }); + + const req = buildReq(); + middleware(req, buildRes() as unknown as Response, jest.fn() as unknown as NextFunction); + + expect(consoleErrorSpy).toHaveBeenCalledWith('envoyMiddleware: loggerFactory threw', expect.any(Error)); + expect((req as Request & { logger?: unknown }).logger).toBeUndefined(); + }); + + it('does not call the factory again after req.envoy is initialized', async () => { + const loginSpy = jest + .spyOn(EnvoyPluginAPI, 'loginAsPlugin') + .mockResolvedValue({ access_token: 'test-token', expires_in: 3600 } as never); + try { + const logger = buildLogger(); + const loggerFactory = jest.fn(() => logger); + const middleware = envoyMiddleware({ + secret: 'test-secret', + algorithm: 'sha256', + encoding: 'base64', + header: 'x-envoy-signature', + loggerFactory, + }); + + // Same body-parser short-circuit / VERIFIED trick as the integration test below. + const req = { + method: 'POST', + originalUrl: '/some/path', + headers: {}, + query: { name: 'checkr' }, + _body: true, + [VERIFIED]: true, + body: { + meta: { + install_id: 'install-1', + location: { id: 'loc-1' }, + company: { id: 'company-1' }, + event: 'entry_sign_in', + }, + payload: { id: 'visitor-1', type: 'visitors' }, + }, + } as unknown as Request; + + await new Promise((resolve, reject) => { + middleware( + req, + buildRes() as unknown as Response, + ((err?: unknown) => (err ? reject(err) : resolve())) as NextFunction, + ); + }); + + // Factory should be invoked exactly once — enrichment happens via .child() + // downstream, not by re-invoking the factory. + expect(loggerFactory).toHaveBeenCalledTimes(1); + expect(loggerFactory).toHaveBeenCalledWith(req, { integrationName: 'checkr' }); + } finally { + loginSpy.mockRestore(); + } + }); +}); + +describe('envoyLoggerContextMiddleware', () => { + /* eslint-disable no-console */ + const originalConsoleError = console.error; + let consoleErrorSpy: jest.Mock; + + beforeEach(() => { + consoleErrorSpy = jest.fn(); + console.error = consoleErrorSpy; + }); + + afterEach(() => { + console.error = originalConsoleError; + }); + /* eslint-enable no-console */ + + function buildEnvoyReqWithLogger(logger: StructuredLogger | undefined): Request { + return { + method: 'POST', + originalUrl: '/some/path', + headers: {}, + query: { name: 'checkr' }, + envoy: { + meta: { + install_id: 'install-1', + location: { id: 'loc-1' }, + company: { id: 'company-1' }, + event: 'entry_sign_in', + }, + payload: { id: 'visitor-1', type: 'visitors' }, + }, + ...(logger ? { logger } : {}), + } as unknown as Request; + } + + it('replaces req.logger with a child carrying the full Envoy context', () => { + const childLogger = buildLogger(); + const baseLogger = buildLogger(); + baseLogger.child.mockReturnValue(childLogger); + + const req = buildEnvoyReqWithLogger(baseLogger); + const next = jest.fn() as unknown as NextFunction; + + envoyLoggerContextMiddleware()(req, buildRes() as unknown as Response, next); + + expect(baseLogger.child).toHaveBeenCalledWith({ + integrationName: 'checkr', + installId: 'install-1', + locationId: 'loc-1', + companyId: 'company-1', + recordId: 'visitor-1', + recordType: 'visitors', + event: 'entry_sign_in', + category: 'Visitor', + }); + expect((req as Request & { logger?: unknown }).logger).toBe(childLogger); + expect(next).toHaveBeenCalledTimes(1); + }); + + it('uses the fallback factory when req.logger is absent', () => { + const constructed = buildLogger(); + const fallback = jest.fn(() => constructed); + const req = buildEnvoyReqWithLogger(undefined); + const next = jest.fn() as unknown as NextFunction; + + envoyLoggerContextMiddleware({ fallback })(req, buildRes() as unknown as Response, next); + + expect(fallback).toHaveBeenCalledTimes(1); + const [fallbackReq, fallbackCtx] = fallback.mock.calls[0] as unknown as [Request, unknown]; + expect(fallbackReq).toBe(req); + expect(fallbackCtx).toEqual({ + integrationName: 'checkr', + installId: 'install-1', + locationId: 'loc-1', + companyId: 'company-1', + recordId: 'visitor-1', + recordType: 'visitors', + event: 'entry_sign_in', + category: 'Visitor', + }); + expect((req as Request & { logger?: unknown }).logger).toBe(constructed); + expect(next).toHaveBeenCalledTimes(1); + }); + + it('is a no-op when req.logger is absent and no fallback is provided', () => { + const req = buildEnvoyReqWithLogger(undefined); + const next = jest.fn() as unknown as NextFunction; + + envoyLoggerContextMiddleware()(req, buildRes() as unknown as Response, next); + + expect((req as Request & { logger?: unknown }).logger).toBeUndefined(); + expect(next).toHaveBeenCalledTimes(1); + }); +}); + +describe('extractLoggerContext', () => { + function buildEnvoyRequest(envoy: unknown, query: Record = {}): EnvoyRequest { + return { envoy, query } as unknown as EnvoyRequest; + } + + it('pulls every standard Envoy field from an event request', () => { + const req = buildEnvoyRequest( + { + meta: { + install_id: 'install-1', + location: { id: 'loc-1' }, + company: { id: 'company-1' }, + event: 'invite_created', + }, + payload: { id: 'invite-1', type: 'invites' }, + }, + { name: 'checkr' }, + ); + + expect(extractLoggerContext(req)).toEqual({ + integrationName: 'checkr', + installId: 'install-1', + locationId: 'loc-1', + companyId: 'company-1', + recordId: 'invite-1', + recordType: 'invites', + event: 'invite_created', + category: 'Visitor', + }); + }); + + it('omits event/category for route requests (no `event` on meta)', () => { + const req = buildEnvoyRequest( + { + meta: { + install_id: 'install-1', + location: { id: 'loc-1' }, + company: { id: 'company-1' }, + route: 'validate', + }, + payload: {}, + }, + { name: 'checkr' }, + ); + + const ctx = extractLoggerContext(req); + expect(ctx.event).toBeUndefined(); + expect(ctx.category).toBeUndefined(); + expect(ctx.installId).toBe('install-1'); + }); + + it('maps unrecognized events to category "Unrecognized"', () => { + const req = buildEnvoyRequest({ + meta: { install_id: 'i', location: { id: 'l' }, company: { id: 'c' }, event: 'mystery_event' }, + payload: {}, + }); + + expect(extractLoggerContext(req)).toMatchObject({ + event: 'mystery_event', + category: 'Unrecognized', + }); + }); + + it('maps workplace / desks / communication events to their categories', () => { + const makeReq = (event: string) => buildEnvoyRequest({ meta: { event }, payload: {} }); + + expect(extractLoggerContext(makeReq('employee_entry_sign_in')).category).toBe('Workplace'); + expect(extractLoggerContext(makeReq('desk_sign_in')).category).toBe('Desks'); + expect(extractLoggerContext(makeReq('takeover_started')).category).toBe('Communication'); + }); + + it('returns just integrationName when req.envoy is missing', () => { + const req = buildEnvoyRequest(undefined, { name: 'checkr' }); + + expect(extractLoggerContext(req)).toEqual({ integrationName: 'checkr' }); + }); + + it('degrades gracefully when meta/payload fields are missing', () => { + const req = buildEnvoyRequest({ meta: {}, payload: undefined }, {}); + + expect(extractLoggerContext(req)).toEqual({ + integrationName: undefined, + installId: undefined, + locationId: undefined, + companyId: undefined, + recordId: undefined, + recordType: undefined, + }); + }); +});