From f4f9224c68d4b441d56efb5d7822a72e9a6a9eb4 Mon Sep 17 00:00:00 2001 From: Julien Gautier Date: Wed, 13 May 2026 18:07:06 +0200 Subject: [PATCH] fix(portal-bff): audit writes use raw INSERT (audit_writer has no SELECT for RETURNING) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit manual smoke after #120 returned 500 on the first /auth/logout : PostgresError code 42501 — permission denied for table events acl looked correct (audit_writer=a/audit_owner), has_*_privilege returned t everywhere, and a manual psql `INSERT INTO audit.events` succeeded after SET LOCAL ROLE audit_writer. but the same INSERT WITH `RETURNING id` failed with the exact same error. root cause: tx.auditEvent.create() in prisma emits `INSERT … RETURNING *` to hydrate the entity it returns, and postgres requires SELECT on every column in RETURNING. audit_writer has INSERT only per adr-0013's append-only-by-role contract. RETURNING fails with "permission denied for table X" — and the message says nothing about SELECT or RETURNING, which made the bug take a long debug session to isolate. fix: AuditWriter.recordEvent now uses tx.$executeRawUnsafe with a parameterised raw INSERT instead of the orm create(). the role contract stays strict (audit_writer keeps INSERT only — no SELECT, UPDATE, DELETE, TRUNCATE). the alternative — GRANT SELECT to audit_writer — would have collapsed the writer / reader role separation that adr-0013 hinges on, so we went the other way. bonus: also fixes an env-sensitivity bug in auth.controller.spec.ts. the test asserting `session.absoluteExpiresAt == createdAt + 43_200 * 1000` was reading the default via readSessionTimeouts() but didn't override SESSION_ABSOLUTE_TIMEOUT_SECONDS. apps/portal-bff/ .env may carry a custom value (it did during the audit debugging), making the test fail non-deterministically. now it deletes the env var before, restores after — same pattern as the other env-touching tests in this file. 144/144 specs pass under the clean-env repro: env -u REDIS_URL -u SESSION_SECRET -u SESSION_ENCRYPTION_KEY \ -u SESSION_IDLE_TIMEOUT_SECONDS -u SESSION_ABSOLUTE_TIMEOUT_SECONDS \ -u LOG_USER_ID_SALT -u DATABASE_URL -u ENTRA_* \ pnpm exec nx run-many -t test lint build --projects=portal-bff notable shape choices: - gen_random_uuid() server-side instead of prisma's @default(uuid()) client-side. the model still declares @default for future orm reads by audit_reader; the write path now uses postgres's built-in (available since 13, target is 17). - explicit enum + jsonb casts ($2::"audit"."AuditAudience" etc.) because parameters travel as TEXT on the wire. - parameterised via $1, $2, …; never interpolated. a spec pins this with a sql-injection-shaped eventType input. unchanged: schema, migration, role grants, ADR-0013 contract. --- .../src/audit/audit.service.spec.ts | 194 +++++++++++------- apps/portal-bff/src/audit/audit.service.ts | 57 +++-- .../src/auth/auth.controller.spec.ts | 42 ++-- 3 files changed, 187 insertions(+), 106 deletions(-) diff --git a/apps/portal-bff/src/audit/audit.service.spec.ts b/apps/portal-bff/src/audit/audit.service.spec.ts index 960686f..82cd86a 100644 --- a/apps/portal-bff/src/audit/audit.service.spec.ts +++ b/apps/portal-bff/src/audit/audit.service.spec.ts @@ -2,26 +2,29 @@ import { Test } from '@nestjs/testing'; import { trace } from '@opentelemetry/api'; import { ClsService } from 'nestjs-cls'; import { PrismaService } from 'nestjs-prisma'; -import { Prisma } from '@prisma/client'; import { AuditWriter } from './audit.service'; import type { AuditEventInput } from './audit.types'; import { HashUserIdService } from './hash-user-id.service'; -interface AuditEventCreateCall { - data: { - eventType: string; - audience: 'workforce' | 'customer'; - outcome: 'success' | 'failure' | 'denied'; - subject: string | null; - actorIdHash: string | null; - traceId: string | null; - payload: Prisma.InputJsonValue | typeof Prisma.JsonNull; - }; +/** + * Fields of an audit row as captured from the parameterised raw + * INSERT — same positional order as the SQL placeholders. Anything + * read from the mock goes through `extractInsertedRow` so the + * tests assert against named fields rather than raw `$executeRawUnsafe` + * argument indices. + */ +interface InsertedRow { + eventType: unknown; + audience: unknown; + outcome: unknown; + subject: unknown; + actorIdHash: unknown; + traceId: unknown; + payloadJson: unknown; } interface MockTx { $executeRawUnsafe: jest.Mock; - auditEvent: { create: jest.Mock }; } interface MockPrisma { @@ -32,7 +35,6 @@ interface MockPrisma { function buildMocks(): { prisma: MockPrisma; cls: { get: jest.Mock } } { const tx: MockTx = { $executeRawUnsafe: jest.fn().mockResolvedValue(0), - auditEvent: { create: jest.fn().mockResolvedValue(undefined) }, }; const prisma: MockPrisma = { tx, @@ -42,6 +44,25 @@ function buildMocks(): { prisma: MockPrisma; cls: { get: jest.Mock } } { return { prisma, cls }; } +/** + * Pull the inserted-row fields out of the `$executeRawUnsafe` mock. + * `recordEvent` calls `$executeRawUnsafe` twice — first to `SET LOCAL + * ROLE audit_writer`, then to issue the parameterised INSERT. The + * INSERT call has args (sql, eventType, audience, outcome, subject, + * actorIdHash, traceId, payloadJson). + */ +function extractInsertedRow(prisma: MockPrisma): InsertedRow { + const calls = prisma.tx.$executeRawUnsafe.mock.calls; + const insertCall = calls[1]; + if (!insertCall) { + throw new Error( + `expected $executeRawUnsafe to be called at least twice (SET ROLE + INSERT), got ${calls.length}`, + ); + } + const [, eventType, audience, outcome, subject, actorIdHash, traceId, payloadJson] = insertCall; + return { eventType, audience, outcome, subject, actorIdHash, traceId, payloadJson }; +} + async function createSubject(): Promise<{ writer: AuditWriter; prisma: MockPrisma; @@ -75,35 +96,69 @@ describe('AuditWriter', () => { await writer.recordEvent(baseInput); expect(prisma.$transaction).toHaveBeenCalledTimes(1); - expect(prisma.tx.$executeRawUnsafe).toHaveBeenCalledWith('SET LOCAL ROLE audit_writer'); - // SET ROLE must precede the INSERT, otherwise the runtime - // privilege check happens with the wrong role. - const setRoleOrder = prisma.tx.$executeRawUnsafe.mock.invocationCallOrder[0]; - const createOrder = prisma.tx.auditEvent.create.mock.invocationCallOrder[0]; - expect(setRoleOrder).toBeLessThan(createOrder); + // recordEvent runs two raw statements per call: SET ROLE then + // INSERT. SET ROLE must come first so the INSERT's privilege + // check is against audit_writer, not the BFF's connection role. + const calls = prisma.tx.$executeRawUnsafe.mock.calls; + expect(calls.length).toBeGreaterThanOrEqual(2); + expect(calls[0]?.[0]).toBe('SET LOCAL ROLE audit_writer'); + expect(calls[1]?.[0]).toMatch(/INSERT INTO "audit"\."events"/); }); - it('passes the input fields through to the create call', async () => { + it('does NOT use Prisma ORM create() — the raw INSERT keeps audit_writer free of SELECT', async () => { + // Bypassing the ORM is the explicit choice that lets ADR-0013's + // append-only role contract hold. Prisma's create() emits + // `INSERT … RETURNING *`, and RETURNING requires SELECT. Pin + // the constraint so a well-meaning refactor can't silently + // reintroduce the bug. + const { writer, prisma } = await createSubject(); + await writer.recordEvent(baseInput); + + // Sanity check: the only writes go through $executeRawUnsafe. + // No other tx method should be called. + const allowedTxKeys = new Set(['$executeRawUnsafe']); + const observedTxKeys = Object.keys(prisma.tx); + expect(observedTxKeys.every((k) => allowedTxKeys.has(k))).toBe(true); + }); + + it('parameterises the INSERT — never inlines values into SQL', async () => { + const { writer, prisma } = await createSubject(); + await writer.recordEvent({ + ...baseInput, + eventType: "auth'; DROP TABLE events; --", + }); + + const insertCall = prisma.tx.$executeRawUnsafe.mock.calls[1]; + const sql = insertCall?.[0] as string; + // SQL itself must be the parameterised template; the malicious + // eventType has to land in the params array, not concatenated + // into the SQL. + expect(sql).toContain('$1'); + expect(sql).not.toContain('DROP TABLE'); + expect(insertCall?.[1]).toBe("auth'; DROP TABLE events; --"); + }); + + it('passes the input fields through positionally to the parameterised INSERT', async () => { const { writer, prisma } = await createSubject(); await writer.recordEvent({ ...baseInput, payload: { route: '/auth/login', clientId: 'spa' }, }); - const call = prisma.tx.auditEvent.create.mock.calls[0]?.[0] as AuditEventCreateCall; - expect(call.data.eventType).toBe('auth.login'); - expect(call.data.audience).toBe('workforce'); - expect(call.data.outcome).toBe('success'); - expect(call.data.subject).toBe('user:42'); - expect(call.data.payload).toEqual({ route: '/auth/login', clientId: 'spa' }); + const row = extractInsertedRow(prisma); + expect(row.eventType).toBe('auth.login'); + expect(row.audience).toBe('workforce'); + expect(row.outcome).toBe('success'); + expect(row.subject).toBe('user:42'); + expect(row.payloadJson).toBe(JSON.stringify({ route: '/auth/login', clientId: 'spa' })); }); - it('records Prisma.JsonNull when no payload is provided', async () => { + it('sends payload as null (JSONB column nullable) when no payload is provided', async () => { const { writer, prisma } = await createSubject(); await writer.recordEvent(baseInput); - const call = prisma.tx.auditEvent.create.mock.calls[0]?.[0] as AuditEventCreateCall; - expect(call.data.payload).toBe(Prisma.JsonNull); + const row = extractInsertedRow(prisma); + expect(row.payloadJson).toBeNull(); }); it('reads actorIdHash from CLS when not passed explicitly', async () => { @@ -113,8 +168,7 @@ describe('AuditWriter', () => { await writer.recordEvent(baseInput); expect(cls.get).toHaveBeenCalledWith('actorIdHash'); - const call = prisma.tx.auditEvent.create.mock.calls[0]?.[0] as AuditEventCreateCall; - expect(call.data.actorIdHash).toBe('hash-from-cls'); + expect(extractInsertedRow(prisma).actorIdHash).toBe('hash-from-cls'); }); it('prefers an explicit actorIdHash over the CLS-resolved one', async () => { @@ -123,8 +177,7 @@ describe('AuditWriter', () => { await writer.recordEvent({ ...baseInput, actorIdHash: 'hash-from-input' }); - const call = prisma.tx.auditEvent.create.mock.calls[0]?.[0] as AuditEventCreateCall; - expect(call.data.actorIdHash).toBe('hash-from-input'); + expect(extractInsertedRow(prisma).actorIdHash).toBe('hash-from-input'); }); it('stores actorIdHash = null when neither input nor CLS has one', async () => { @@ -133,8 +186,7 @@ describe('AuditWriter', () => { await writer.recordEvent(baseInput); - const call = prisma.tx.auditEvent.create.mock.calls[0]?.[0] as AuditEventCreateCall; - expect(call.data.actorIdHash).toBeNull(); + expect(extractInsertedRow(prisma).actorIdHash).toBeNull(); }); it('captures the active OTel trace id', async () => { @@ -145,8 +197,7 @@ describe('AuditWriter', () => { const { writer, prisma } = await createSubject(); await writer.recordEvent(baseInput); - const call = prisma.tx.auditEvent.create.mock.calls[0]?.[0] as AuditEventCreateCall; - expect(call.data.traceId).toBe('abc123'); + expect(extractInsertedRow(prisma).traceId).toBe('abc123'); } finally { getActiveSpanSpy.mockRestore(); } @@ -159,8 +210,7 @@ describe('AuditWriter', () => { const { writer, prisma } = await createSubject(); await writer.recordEvent(baseInput); - const call = prisma.tx.auditEvent.create.mock.calls[0]?.[0] as AuditEventCreateCall; - expect(call.data.traceId).toBeNull(); + expect(extractInsertedRow(prisma).traceId).toBeNull(); } finally { getActiveSpanSpy.mockRestore(); } @@ -169,7 +219,8 @@ describe('AuditWriter', () => { it('propagates the underlying error — no catch-and-swallow', async () => { const { writer, prisma } = await createSubject(); const dbError = new Error('permission denied for table events'); - prisma.tx.auditEvent.create.mockRejectedValueOnce(dbError); + // First call (SET ROLE) succeeds, second (INSERT) rejects. + prisma.tx.$executeRawUnsafe.mockResolvedValueOnce(0).mockRejectedValueOnce(dbError); await expect(writer.recordEvent(baseInput)).rejects.toThrow( 'permission denied for table events', @@ -186,13 +237,13 @@ describe('AuditWriter — typed event methods', () => { sessionId: 'sid-1', }); expect(hashUserId.hash).toHaveBeenCalledWith('user-oid'); - const call = prisma.tx.auditEvent.create.mock.calls[0]?.[0] as AuditEventCreateCall; - expect(call.data.eventType).toBe('auth.sign_in'); - expect(call.data.audience).toBe('workforce'); - expect(call.data.outcome).toBe('success'); - expect(call.data.actorIdHash).toBe('hash(user-oid)'); - expect(call.data.subject).toBe('session:sid-1'); - expect(call.data.payload).toEqual({ amr: ['pwd', 'mfa'] }); + const row = extractInsertedRow(prisma); + expect(row.eventType).toBe('auth.sign_in'); + expect(row.audience).toBe('workforce'); + expect(row.outcome).toBe('success'); + expect(row.actorIdHash).toBe('hash(user-oid)'); + expect(row.subject).toBe('session:sid-1'); + expect(row.payloadJson).toBe(JSON.stringify({ amr: ['pwd', 'mfa'] })); }); }); @@ -201,11 +252,11 @@ describe('AuditWriter — typed event methods', () => { const { writer, prisma, hashUserId } = await createSubject(); await writer.signInFailed({ failureKind: 'state-mismatch' }); expect(hashUserId.hash).not.toHaveBeenCalled(); - const call = prisma.tx.auditEvent.create.mock.calls[0]?.[0] as AuditEventCreateCall; - expect(call.data.eventType).toBe('auth.sign_in.failed'); - expect(call.data.outcome).toBe('failure'); - expect(call.data.actorIdHash).toBeNull(); - expect(call.data.payload).toEqual({ failureKind: 'state-mismatch' }); + const row = extractInsertedRow(prisma); + expect(row.eventType).toBe('auth.sign_in.failed'); + expect(row.outcome).toBe('failure'); + expect(row.actorIdHash).toBeNull(); + expect(row.payloadJson).toBe(JSON.stringify({ failureKind: 'state-mismatch' })); }); it('merges payload with failureKind under the same key', async () => { @@ -214,20 +265,21 @@ describe('AuditWriter — typed event methods', () => { failureKind: 'entra-error', payload: { entraError: 'access_denied', entraErrorDescription: 'user cancelled' }, }); - const call = prisma.tx.auditEvent.create.mock.calls[0]?.[0] as AuditEventCreateCall; - expect(call.data.payload).toEqual({ - failureKind: 'entra-error', - entraError: 'access_denied', - entraErrorDescription: 'user cancelled', - }); + const row = extractInsertedRow(prisma); + expect(row.payloadJson).toBe( + JSON.stringify({ + failureKind: 'entra-error', + entraError: 'access_denied', + entraErrorDescription: 'user cancelled', + }), + ); }); it('hashes the actor oid when one is provided (rare — identity-after-rejection path)', async () => { const { writer, prisma, hashUserId } = await createSubject(); await writer.signInFailed({ failureKind: 'amr-missing', actor: { oid: 'user-oid' } }); expect(hashUserId.hash).toHaveBeenCalledWith('user-oid'); - const call = prisma.tx.auditEvent.create.mock.calls[0]?.[0] as AuditEventCreateCall; - expect(call.data.actorIdHash).toBe('hash(user-oid)'); + expect(extractInsertedRow(prisma).actorIdHash).toBe('hash(user-oid)'); }); }); @@ -236,11 +288,11 @@ describe('AuditWriter — typed event methods', () => { const { writer, prisma, hashUserId } = await createSubject(); await writer.signOut({ actor: { oid: 'user-oid' }, sessionId: 'sid-2' }); expect(hashUserId.hash).toHaveBeenCalledWith('user-oid'); - const call = prisma.tx.auditEvent.create.mock.calls[0]?.[0] as AuditEventCreateCall; - expect(call.data.eventType).toBe('auth.sign_out'); - expect(call.data.outcome).toBe('success'); - expect(call.data.actorIdHash).toBe('hash(user-oid)'); - expect(call.data.subject).toBe('session:sid-2'); + const row = extractInsertedRow(prisma); + expect(row.eventType).toBe('auth.sign_out'); + expect(row.outcome).toBe('success'); + expect(row.actorIdHash).toBe('hash(user-oid)'); + expect(row.subject).toBe('session:sid-2'); }); }); @@ -254,11 +306,13 @@ describe('AuditWriter — typed event methods', () => { ageMs: 13 * 60 * 60 * 1000, }); expect(hashUserId.hash).toHaveBeenCalledWith('user-oid'); - const call = prisma.tx.auditEvent.create.mock.calls[0]?.[0] as AuditEventCreateCall; - expect(call.data.eventType).toBe('auth.session.expired'); - expect(call.data.outcome).toBe('success'); - expect(call.data.subject).toBe('session:sid-3'); - expect(call.data.payload).toEqual({ reason: 'absolute', ageMs: 13 * 60 * 60 * 1000 }); + const row = extractInsertedRow(prisma); + expect(row.eventType).toBe('auth.session.expired'); + expect(row.outcome).toBe('success'); + expect(row.subject).toBe('session:sid-3'); + expect(row.payloadJson).toBe( + JSON.stringify({ reason: 'absolute', ageMs: 13 * 60 * 60 * 1000 }), + ); }); }); }); diff --git a/apps/portal-bff/src/audit/audit.service.ts b/apps/portal-bff/src/audit/audit.service.ts index a8d83be..288b664 100644 --- a/apps/portal-bff/src/audit/audit.service.ts +++ b/apps/portal-bff/src/audit/audit.service.ts @@ -2,7 +2,6 @@ import { Injectable } from '@nestjs/common'; import { trace } from '@opentelemetry/api'; import { ClsService } from 'nestjs-cls'; import { PrismaService } from 'nestjs-prisma'; -import { Prisma } from '@prisma/client'; import type { AuditEventInput, SignInActor, @@ -118,6 +117,7 @@ export class AuditWriter { const traceId = trace.getActiveSpan()?.spanContext().traceId ?? null; const actorIdHash = input.actorIdHash ?? this.cls.get('actorIdHash') ?? null; + const payloadJson = input.payload === undefined ? null : JSON.stringify(input.payload); await this.prisma.$transaction(async (tx) => { // Lock the connection to audit_writer for the duration of this @@ -125,27 +125,40 @@ export class AuditWriter { // pool's next consumer sees the original role. await tx.$executeRawUnsafe(`SET LOCAL ROLE audit_writer`); - await tx.auditEvent.create({ - data: { - eventType: input.eventType, - audience: input.audience, - outcome: input.outcome, - subject: input.subject ?? null, - actorIdHash, - traceId, - payload: this.toJsonInput(input.payload), - }, - }); + // Deliberately NOT `tx.auditEvent.create(...)`. The Prisma ORM + // create() emits `INSERT … RETURNING *` to hydrate the entity + // it returns, and Postgres requires SELECT on every column + // listed in RETURNING. `audit_writer` is granted INSERT only + // (ADR-0013 §"Append-only by role grants"); RETURNING fails + // with the deeply misleading "permission denied for table + // events" error code 42501. Raw parameterised INSERT keeps + // the role contract strict — audit_writer never needs SELECT. + // + // `gen_random_uuid()` is built into Postgres 13+ (the dev / + // prod target is 17). The enum + jsonb casts are needed + // because the parameter values are sent as TEXT over the + // wire. + await tx.$executeRawUnsafe( + `INSERT INTO "audit"."events" + (id, event_type, audience, outcome, subject, actor_id_hash, trace_id, payload) + VALUES ( + gen_random_uuid(), + $1, + $2::"audit"."AuditAudience", + $3::"audit"."AuditOutcome", + $4, + $5, + $6, + $7::jsonb + )`, + input.eventType, + input.audience, + input.outcome, + input.subject ?? null, + actorIdHash, + traceId, + payloadJson, + ); }); } - - // Prisma's `Json` field accepts `Prisma.JsonNull` (null literal in - // SQL JSONB) or a serialisable value; explicit `undefined` skips - // the column. Map `payload` accordingly. - private toJsonInput( - payload: AuditEventInput['payload'], - ): Prisma.InputJsonValue | typeof Prisma.JsonNull { - if (payload === undefined) return Prisma.JsonNull; - return payload as Prisma.InputJsonValue; - } } diff --git a/apps/portal-bff/src/auth/auth.controller.spec.ts b/apps/portal-bff/src/auth/auth.controller.spec.ts index aea05c6..799f3d5 100644 --- a/apps/portal-bff/src/auth/auth.controller.spec.ts +++ b/apps/portal-bff/src/auth/auth.controller.spec.ts @@ -229,22 +229,36 @@ describe('AuthController.callback', () => { }); it('records createdAt + absoluteExpiresAt on the session (ADR-0010 §"TTL policy")', async () => { - const before = Date.now(); - const { controller } = makeController(); - const res = makeResStub(); - const session = makeSessionStub(); - const req = makeReqStub({ - signedCookies: { [PRE_AUTH_COOKIE_NAME]: JSON.stringify(PRE_AUTH) }, - session, - }); + // Force the ADR-0010 default for this test — apps/portal-bff/.env + // may have a custom SESSION_ABSOLUTE_TIMEOUT_SECONDS for local + // experiments and Nx auto-loads it. Asserting on the default in + // a test that doesn't override it then fails non-deterministically. + const originalAbsolute = process.env['SESSION_ABSOLUTE_TIMEOUT_SECONDS']; + delete process.env['SESSION_ABSOLUTE_TIMEOUT_SECONDS']; + try { + const before = Date.now(); + const { controller } = makeController(); + const res = makeResStub(); + const session = makeSessionStub(); + const req = makeReqStub({ + signedCookies: { [PRE_AUTH_COOKIE_NAME]: JSON.stringify(PRE_AUTH) }, + session, + }); - await controller.callback(req, res, 'auth-code', PRE_AUTH.state); + await controller.callback(req, res, 'auth-code', PRE_AUTH.state); - const after = Date.now(); - expect(session.createdAt).toBeGreaterThanOrEqual(before); - expect(session.createdAt).toBeLessThanOrEqual(after); - // Default absoluteSeconds = 43200 (12 h) per ADR-0010. - expect(session.absoluteExpiresAt).toBe((session.createdAt as number) + 43_200 * 1000); + const after = Date.now(); + expect(session.createdAt).toBeGreaterThanOrEqual(before); + expect(session.createdAt).toBeLessThanOrEqual(after); + // Default absoluteSeconds = 43200 (12 h) per ADR-0010. + expect(session.absoluteExpiresAt).toBe((session.createdAt as number) + 43_200 * 1000); + } finally { + if (originalAbsolute === undefined) { + delete process.env['SESSION_ABSOLUTE_TIMEOUT_SECONDS']; + } else { + process.env['SESSION_ABSOLUTE_TIMEOUT_SECONDS'] = originalAbsolute; + } + } }); it('registers the new session in the user_sessions index after save', async () => {