edr-platform/packages/api-common/src/logging/request-log.middleware.ts

import { randomUUID } from "node:crypto";
import { Injectable, NestMiddleware } from "@nestjs/common";

import {
  RequestLogContext,
  logCtx,
  runWithLogContext,
} from "./request-context";

/**
 * Structural request/response shapes — express types are not a dependency of
 * this package (they arrive under @nestjs/platform-express in the apps).
 */
interface LoggedRequest {
  method: string;
  url: string;
  originalUrl?: string;
  baseUrl?: string;
  route?: { path?: string };
  headers: Record<string, string | string[] | undefined>;
  ip?: string;
  query?: Record<string, unknown>;
  /** Set by the IAM JwtGuard AFTER this middleware runs — read at emit time. */
  user?: AuthenticatedUser | null;
  currentUnitId?: string;
}

/**
 * The subset of `TCurrentUser` (@tria-plc/api-common) the log line reads.
 * Everything here is an identifier, a key or a status — the personal fields on
 * that type (name, email, username, phoneNumber) are deliberately absent so
 * they cannot be picked up by accident.
 */
interface AuthenticatedUser {
  id?: string;
  sub?: string;
  userId?: string;
  sessionId?: string;
  userType?: string;
  status?: string;
  roles?: { key?: string }[];
  permissions?: unknown[];
  employee?: {
    id?: string;
    organizationId?: string;
    unitId?: string;
    position?: {
      id?: string;
      key?: string;
      employeePositionId?: string;
      isDelegate?: boolean;
      delegatorId?: string;
      positionType?: { key?: string };
    };
  };
}

interface LoggedResponse {
  statusCode: number;
  writableEnded?: boolean;
  setHeader(name: string, value: string): void;
  on(event: string, listener: () => void): void;
}

const header = (req: LoggedRequest, name: string): string | undefined => {
  const value = req.headers[name];
  return Array.isArray(value) ? value[0] : value;
};

const userId = (req: LoggedRequest): string | undefined =>
  req.user?.id ?? req.user?.sub ?? req.user?.userId;

/**
 * Who the caller was acting as — WITHOUT any personal data. Ids, role/position
 * keys and statuses only: enough to answer "which desk did this", "was it a
 * delegate", "which tenant", and to spot an authorization problem, with nothing
 * that identifies the human behind the account beyond the opaque user id.
 *
 * `authenticated: false` with `hasBearer: true` is the signature of a rejected
 * token (expired session, bad signature) as opposed to a missing one.
 */
const authContext = (req: LoggedRequest): Record<string, unknown> => {
  const user = req.user;
  const position = user?.employee?.position;
  return {
    authenticated: Boolean(user),
    hasBearer: header(req, "authorization")?.startsWith("Bearer ") ?? false,
    // Which frontend called — /auth/login rejects cross-audience credentials on it.
    clientApp: header(req, "x-client-app"),
    userId: userId(req),
    sessionId: user?.sessionId,
    userType: user?.userType,
    userStatus: user?.status,
    roles: user?.roles?.map((role) => role.key).filter(Boolean),
    // Count only: the full grant list is hundreds of keys and would dwarf the line.
    permissionCount: user?.permissions?.length,
    employeeId: user?.employee?.id,
    organizationId: user?.employee?.organizationId,
    unitId: user?.employee?.unitId ?? req.currentUnitId,
    positionId: position?.id,
    positionKey: position?.key,
    positionType: position?.positionType?.key,
    employeePositionId: position?.employeePositionId,
    // Acting on someone else's behalf — the first thing to check when a staff
    // action lands under an unexpected desk.
    isDelegate: position?.isDelegate,
    delegatorId: position?.delegatorId,
    // Tenant/scope headers the frontends send alongside the token.
    projectId:
      header(req, "current-project-id") ?? header(req, "x-current-project-id"),
  };
};

/**
 * Opens an AsyncLocalStorage context for the request (so anything downstream
 * can `logCtx(...)` into it) and emits ONE canonical JSON line per request when
 * the response ends — request metadata plus every data point collected during
 * the flow, on the same Nest logger transport as the rest of the app.
 *
 * Base fields win over collected context on key collisions, so a stray
 * `logCtx({ status })` can never corrupt the fields dashboards filter on.
 *
 * Apply FIRST in `configure()`: middleware registered before this one runs
 * outside the context and its `logCtx` calls are silently dropped.
 */
@Injectable()
export class RequestLogMiddleware implements NestMiddleware {
  use(req: LoggedRequest, res: LoggedResponse, next: () => void): void {
    const start = Date.now();
    const requestId = header(req, "x-request-id") ?? randomUUID();
    res.setHeader("x-request-id", requestId);

    // Held by reference, NOT read back through the ALS at emit time: response
    // "finish"/"close" listeners are plain EventEmitter callbacks, which Node
    // does not bind to the async context they were registered in — getStore()
    // there returns whatever context happened to call res.end().
    const ctx: RequestLogContext = {};

    runWithLogContext(ctx, () => {
      logCtx({ requestId });

      let emitted = false;
      // "finish" covers normal responses; "close" catches client aborts, where
      // "finish" never fires and the request would vanish from the logs.
      const emit = () => {
        if (emitted) return;
        emitted = true;

        const url = req.originalUrl ?? req.url;
        const status = res.statusCode;
        const durationMs = Date.now() - start;

        const line = {
          ...ctx,
          // Fields the Nest console prefix used to carry. They are IN the JSON
          // now because this line is written raw (see below) — a log shipper
          // needs level and time as parsable fields, not as console decoration.
          time: new Date().toISOString(),
          level: status >= 500 ? "error" : status >= 400 ? "warn" : "info",
          logger: "request",
          type: "http_request",
          requestId,
          method: req.method,
          route: req.route?.path
            ? `${req.baseUrl ?? ""}${req.route.path}`
            : undefined,
          url,
          status,
          durationMs,
          userId: userId(req),
          // Read at emit time on purpose: the guard populates req.user long
          // after this middleware handed control on.
          auth: authContext(req),
          ip: req.ip,
          userAgent: header(req, "user-agent"),
          query:
            req.query && Object.keys(req.query).length ? req.query : undefined,
          aborted: res.writableEnded === false ? true : undefined,
        };
        // A circular value pushed into the context must not throw inside a
        // response listener — that would take the process down, not the log.
        let json: string;
        try {
          json = JSON.stringify(line);
        } catch {
          json = JSON.stringify({
            time: line.time,
            level: line.level,
            logger: "request",
            type: "http_request",
            requestId,
            method: req.method,
            url,
            status,
            durationMs,
            contextSerializationFailed: true,
          });
        }

        // Written raw, NOT through Nest's Logger: the console logger wraps every
        // message in "[Nest] pid - date LEVEL [ctx] …", which makes the line
        // un-parsable as JSON. Same destination the Nest logger writes to
        // (stdout, stderr for errors) — only the decoration is dropped.
        (status >= 500 ? process.stderr : process.stdout).write(`${json}\n`);
      };

      res.on("finish", emit);
      res.on("close", emit);

      next();
    });
  }
}