From 8031532873945b1bc4c9343fb67d43965440e375 Mon Sep 17 00:00:00 2001 From: Brandon Corbett Date: Sun, 30 Aug 2026 21:25:28 -0400 Subject: [PATCH] fix(security): stop an audit write failure disabling account lockout Failed attempts were counted by querying auth_events, whose writes swallow every error. Any condition that degraded audit writes while leaving the service running stopped failures being counted, so lockout silently stopped enforcing on every account while authentication carried on. Disk exhaustion, a table lock, a failed migration or connection pool exhaustion would all do it, and the absent records are the same absent records that would have shown it happening. The practical difference was a bounded versus an unbounded guessing attack against a numeric OTP code. Failed attempts now go to auth_failures, written separately from the audit event and read only by the lockout policy, so losing the trail no longer loses the control. Reproduced against a real database by renaming auth_events out from under a running instance: ten failures still counted, the account still locked, and the instance reported degraded. getUserLockoutStatus refuses rather than guessing when it cannot read the counter. An authentication the server cannot vouch for gets the same 423 a locked account gets, instead of being admitted because the count came back empty. Audit write failures are reported where monitoring already looks. GET /health/status answers 200 with a degraded block for five minutes after one. The healthy body is unchanged and the status stays 200, because the service is still serving and should not leave a load balancer over this. That is the defined action NIST 800-53 AU-5 asks for; a log line nobody reads is not. Audit writes themselves still do not throw. 137 call sites await them, many from inside error handlers, so failing there would turn a bookkeeping failure into a failed request, including on the paths that report problems. Closes #211 --- .changeset/quiet-bats-guard.md | 33 +++++++ docs/security-posture.md | 53 +++++++++++ openapi.json | 23 ++++- resources/coverage-badge.svg | 14 +-- src/controllers/health.ts | 19 ++++ src/generated/api.ts | 14 ++- .../20260831010000-create-auth-failures.cjs | 64 +++++++++++++ src/models/authFailures.ts | 69 ++++++++++++++ src/schemas/health.responses.ts | 12 +++ src/services/auditHealth.ts | 62 +++++++++++++ src/services/authEventService.ts | 21 +++-- src/services/authFailureCounter.ts | 88 ++++++++++++++++++ src/services/lockoutPolicyService.ts | 46 +++++----- .../authentication/authentication.spec.ts | 3 +- tests/integration/health/health.spec.ts | 22 +++++ tests/integration/webauthn/webauthn.spec.ts | 3 +- tests/setup/mocks.ts | 11 +++ tests/unit/models/models.spec.ts | 1 + tests/unit/services/auditHealth.spec.ts | 62 +++++++++++++ tests/unit/services/authEventService.spec.ts | 23 ++--- .../unit/services/authFailureCounter.spec.ts | 89 +++++++++++++++++++ .../services/lockoutPolicyService.spec.ts | 43 ++++++--- 22 files changed, 716 insertions(+), 59 deletions(-) create mode 100644 .changeset/quiet-bats-guard.md create mode 100644 src/migrations/20260831010000-create-auth-failures.cjs create mode 100644 src/models/authFailures.ts create mode 100644 src/services/auditHealth.ts create mode 100644 src/services/authFailureCounter.ts create mode 100644 tests/unit/services/auditHealth.spec.ts create mode 100644 tests/unit/services/authFailureCounter.spec.ts diff --git a/.changeset/quiet-bats-guard.md b/.changeset/quiet-bats-guard.md new file mode 100644 index 0000000..91a5fc0 --- /dev/null +++ b/.changeset/quiet-bats-guard.md @@ -0,0 +1,33 @@ +--- +'seamless-auth-api': minor +--- + +Stop an audit write failure from silently disabling account lockout. + +Failed attempts were counted by querying `auth_events`, whose writes swallow every +error. Any condition that degraded audit writes while leaving the service running +stopped failures being counted, so lockout silently stopped enforcing on every +account while authentication carried on. Disk exhaustion, a table lock, a failed +migration or connection pool exhaustion would all do it, and the absent records +are the same absent records that would have shown it happening. The practical +difference was a bounded versus an unbounded guessing attack against a numeric +OTP. + +Failed attempts now go to their own `auth_failures` table, written separately from +the audit event and read only by the lockout policy, so losing the trail no longer +loses the control. + +`getUserLockoutStatus` refuses rather than guessing when it cannot read the +counter: an authentication the server cannot vouch for gets the same `423` a +locked account gets. + +Audit write failures are reported where monitoring already looks. +`GET /health/status` answers `200 { "message": "System up, audit degraded", +"degraded": { "audit": { … } } }` for five minutes after one. The healthy body is +unchanged, so anything already parsing it is unaffected, and the status stays +`200` because the service is still serving. That is the defined action NIST +800-53 AU-5 asks for; a log line nobody reads is not. + +Audit writes themselves still do not throw. 137 call sites await them, many from +inside error handlers, so failing there would turn a bookkeeping failure into a +failed request. diff --git a/docs/security-posture.md b/docs/security-posture.md index f59ff6b..2b9019b 100644 --- a/docs/security-posture.md +++ b/docs/security-posture.md @@ -252,3 +252,56 @@ continues, because failing an authentication over a housekeeping step is worse than briefly exceeding the cap. This is NIST 800-53 AC-10. + +## Audit write failure + +**Posture: the trail may be lost, no security control may be.** + +`AuthEventService` still swallows a failed write to `auth_events`. 137 call sites +await it, many from inside error handlers, so throwing there would turn a +bookkeeping failure into a failed request and would take down the very paths that +report problems. + +What changed is that a failure is no longer silent, and no longer takes anything +with it. + +### Nothing security-relevant is derived from the audit trail + +Account lockout used to count failed attempts by querying `auth_events`. The +control and its telemetry were one data path, and that path fails open: a +condition that degraded audit writes while leaving the service running stopped +failures being counted, so lockout silently stopped enforcing on every account +while authentication carried on. Disk exhaustion, a table lock, a failed +migration or pool exhaustion would all do it, and the missing records are the same +missing records that would have shown it happening. + +Failed attempts are now recorded in `auth_failures`, written separately from the +audit event and read only by the lockout policy. Losing the trail no longer loses +the control. + +### An unknown count means locked + +`getUserLockoutStatus` refuses rather than guessing when it cannot read the +counter. An authentication the server cannot vouch for is refused with the same +`423` a locked account gets, rather than admitted because the count came back +empty. + +### Failures are reported where monitoring already looks + +`GET /health/status` answers `200 { "message": "System up, audit degraded", +"degraded": { "audit": { … } } }` for five minutes after a failed audit write. The +healthy body is unchanged, so anything already parsing it is unaffected, and the +status stays `200` because the service is still serving and should not be pulled +from a load balancer for this. This is the defined action NIST 800-53 AU-5 asks +for on audit logging failure; a line in the application log is not one, because +nothing reads it. + +### What is still accepted + +An audit write that fails is still a lost record. Recording is best effort by +design, and the tradeoff is stated here rather than made by default. A deployment +that needs authentication to fail closed on audit failure does not have that +option today. + +`auth_failures` rows are not pruned, which matches `auth_events`. Retention is +[issue #173](https://github.com/fells-code/seamless-auth-api/issues/173). diff --git a/openapi.json b/openapi.json index d32f160..233ece3 100644 --- a/openapi.json +++ b/openapi.json @@ -3194,10 +3194,29 @@ "description": "HTTP 200", "content": { "application/json": { - "example": { "message": "string" }, + "example": { + "message": "string", + "degraded": { "audit": { "failureCount": 0, "lastFailureAt": "string" } } + }, "schema": { "type": "object", - "properties": { "message": { "type": "string" } }, + "properties": { + "message": { "type": "string" }, + "degraded": { + "type": "object", + "properties": { + "audit": { + "type": "object", + "properties": { + "failureCount": { "type": "number" }, + "lastFailureAt": { "type": "string", "nullable": true } + }, + "required": ["failureCount", "lastFailureAt"] + } + }, + "required": ["audit"] + } + }, "required": ["message"] } } diff --git a/resources/coverage-badge.svg b/resources/coverage-badge.svg index bfd39a2..8bd6c88 100644 --- a/resources/coverage-badge.svg +++ b/resources/coverage-badge.svg @@ -1,5 +1,5 @@ - - coverage: 98.9% + + coverage: 99% @@ -7,17 +7,17 @@ - + - - + + coverage coverage - 98.9% - 98.9% + 99% + 99% diff --git a/src/controllers/health.ts b/src/controllers/health.ts index e63a1b4..db2a984 100644 --- a/src/controllers/health.ts +++ b/src/controllers/health.ts @@ -7,11 +7,30 @@ import { Request, Response } from 'express'; import { getPackageVersion } from '../openapi/document.js'; +import { getAuditHealth } from '../services/auditHealth.js'; import getLogger from '../utils/logger.js'; const logger = getLogger('health'); export const healthCheck = (req: Request, res: Response) => { + const audit = getAuditHealth(); + + // Still 200: the service is serving requests, and a load balancer should not + // pull it out for this. What changes is that an instance which has stopped + // being able to record what it is doing says so, which is the defined action + // NIST 800-53 AU-5 asks for. Nothing is added to the body while healthy. + if (audit.degraded) { + return res.status(200).json({ + message: 'System up, audit degraded', + degraded: { + audit: { + failureCount: audit.failureCount, + lastFailureAt: audit.lastFailureAt, + }, + }, + }); + } + return res.status(200).json({ message: 'System up' }); }; diff --git a/src/generated/api.ts b/src/generated/api.ts index afaa17e..1203192 100644 --- a/src/generated/api.ts +++ b/src/generated/api.ts @@ -3026,11 +3026,23 @@ export interface paths { content: { /** * @example { - * "message": "string" + * "message": "string", + * "degraded": { + * "audit": { + * "failureCount": 0, + * "lastFailureAt": "string" + * } + * } * } */ 'application/json': { message: string; + degraded?: { + audit: { + failureCount: number; + lastFailureAt: string | null; + }; + }; }; }; }; diff --git a/src/migrations/20260831010000-create-auth-failures.cjs b/src/migrations/20260831010000-create-auth-failures.cjs new file mode 100644 index 0000000..97c1d7d --- /dev/null +++ b/src/migrations/20260831010000-create-auth-failures.cjs @@ -0,0 +1,64 @@ +'use strict'; + +/** + * A dedicated store for the failed authentication attempts that drive account + * lockout. + * + * The count used to be derived from `auth_events`, whose writes swallow every + * error, so any condition that degraded audit writes stopped failures being + * counted and silently disabled lockout on every account while authentication + * carried on. The control and its telemetry were the same data path, failing + * open at both ends. + * + * This table exists so losing the audit trail does not lose the control. It is + * written separately from the audit event and carries only what the lockout + * decision needs. + * + * @type {import('sequelize-cli').Migration} + */ +module.exports = { + async up(queryInterface, Sequelize) { + await queryInterface.createTable('auth_failures', { + id: { + type: Sequelize.UUID, + defaultValue: Sequelize.literal('gen_random_uuid()'), + primaryKey: true, + }, + user_id: { + type: Sequelize.UUID, + allowNull: false, + references: { model: 'users', key: 'id' }, + onDelete: 'CASCADE', + }, + type: { + type: Sequelize.STRING, + allowNull: false, + }, + occurred_at: { + type: Sequelize.DATE, + allowNull: false, + defaultValue: Sequelize.literal('CURRENT_TIMESTAMP'), + }, + created_at: { + type: Sequelize.DATE, + allowNull: false, + defaultValue: Sequelize.literal('CURRENT_TIMESTAMP'), + }, + updated_at: { + type: Sequelize.DATE, + allowNull: false, + defaultValue: Sequelize.literal('CURRENT_TIMESTAMP'), + }, + }); + + // The only query this table serves: failures for one user inside a window. + await queryInterface.addIndex('auth_failures', ['user_id', 'occurred_at'], { + name: 'auth_failures_user_id_occurred_at_idx', + }); + }, + + async down(queryInterface) { + await queryInterface.removeIndex('auth_failures', 'auth_failures_user_id_occurred_at_idx'); + await queryInterface.dropTable('auth_failures'); + }, +}; diff --git a/src/models/authFailures.ts b/src/models/authFailures.ts new file mode 100644 index 0000000..0981855 --- /dev/null +++ b/src/models/authFailures.ts @@ -0,0 +1,69 @@ +/* + * Copyright © 2026 Fells Code, LLC + * Licensed under the GNU Affero General Public License v3.0 + * See LICENSE file in the project root for full license information + */ + +import { DataTypes, Model, Sequelize } from 'sequelize'; + +export interface AuthFailureAttributes { + id?: string; + userId: string; + type: string; + occurredAt?: Date; + createdAt?: Date; + updatedAt?: Date; +} + +/** + * A failed authentication attempt, counted by the lockout policy. + * + * Deliberately separate from `AuthEvent`. The audit trail swallows write errors + * so that recording an event can never fail the operation it describes, which is + * the right posture for a record and the wrong one for a security control that + * is derived from it. + */ +export class AuthFailure extends Model implements AuthFailureAttributes { + declare id: string; + declare userId: string; + declare type: string; + declare occurredAt: Date; + declare readonly createdAt: Date; + declare readonly updatedAt: Date; +} + +const initializeAuthFailureModel = (sequelize: Sequelize) => { + AuthFailure.init( + { + id: { + type: DataTypes.UUID, + primaryKey: true, + defaultValue: DataTypes.UUIDV4, + allowNull: false, + }, + userId: { + type: DataTypes.UUID, + allowNull: false, + }, + type: { + type: DataTypes.STRING, + allowNull: false, + }, + occurredAt: { + type: DataTypes.DATE, + allowNull: false, + defaultValue: DataTypes.NOW, + }, + }, + { + sequelize, + modelName: 'AuthFailure', + tableName: 'auth_failures', + underscored: true, + }, + ); + + return AuthFailure; +}; + +export default initializeAuthFailureModel; diff --git a/src/schemas/health.responses.ts b/src/schemas/health.responses.ts index ca7cdd7..a76988d 100644 --- a/src/schemas/health.responses.ts +++ b/src/schemas/health.responses.ts @@ -8,6 +8,18 @@ import { z } from 'zod'; export const HealthStatusResponseSchema = z.object({ message: z.string(), + /** + * Present only when something is wrong, so the healthy body is unchanged for + * anything already parsing it. + */ + degraded: z + .object({ + audit: z.object({ + failureCount: z.number(), + lastFailureAt: z.string().nullable(), + }), + }) + .optional(), }); export const VersionResponseSchema = z.object({ diff --git a/src/services/auditHealth.ts b/src/services/auditHealth.ts new file mode 100644 index 0000000..a040886 --- /dev/null +++ b/src/services/auditHealth.ts @@ -0,0 +1,62 @@ +/* + * Copyright © 2026 Fells Code, LLC + * Licensed under the GNU Affero General Public License v3.0 + * See LICENSE file in the project root for full license information + */ + +import getLogger from '../utils/logger.js'; + +const logger = getLogger('auditHealth'); + +/** + * How long a write failure keeps the process reporting degraded. + * + * Long enough that an intermittent failure is still visible to a monitor that + * scrapes health on a normal interval, short enough that a recovered instance + * stops claiming to be degraded on its own. + */ +export const AUDIT_DEGRADED_WINDOW_MS = 5 * 60 * 1000; + +let failureCount = 0; +let lastFailureAt: Date | null = null; + +/** + * Records that an audit write failed. + * + * NIST 800-53 AU-5 asks for a defined action on audit logging failure. Writing a + * line to the application log is not one, because nothing reads it. This is the + * state `/health/status` reports on, so a monitor already watching health sees an + * instance that has stopped being able to record what it is doing. + */ +export function recordAuditWriteFailure(error: unknown, now = new Date()) { + failureCount += 1; + lastFailureAt = now; + + logger.error( + `Audit write failed, reporting degraded for ${AUDIT_DEGRADED_WINDOW_MS / 1000}s. ` + + `Total failures since start: ${failureCount}. Cause: ${error}`, + ); +} + +export interface AuditHealth { + degraded: boolean; + failureCount: number; + lastFailureAt: string | null; +} + +export function getAuditHealth(now = new Date()): AuditHealth { + const degraded = + lastFailureAt !== null && now.getTime() - lastFailureAt.getTime() < AUDIT_DEGRADED_WINDOW_MS; + + return { + degraded, + failureCount, + lastFailureAt: lastFailureAt ? lastFailureAt.toISOString() : null, + }; +} + +/** Test seam. Process-level state has to be resettable between cases. */ +export function resetAuditHealthForTests() { + failureCount = 0; + lastFailureAt = null; +} diff --git a/src/services/authEventService.ts b/src/services/authEventService.ts index 7ad31ef..cd61f46 100644 --- a/src/services/authEventService.ts +++ b/src/services/authEventService.ts @@ -9,10 +9,9 @@ import { Request } from 'express'; import { AuthEvent } from '../models/authEvents.js'; import type { AuthEventType } from '../schemas/authEvent.types.js'; import type { AuthenticatedRequest } from '../types/types.js'; -import getLogger from '../utils/logger.js'; import { redactMetadata } from '../utils/redaction.js'; - -const logger = getLogger('authEventService'); +import { recordAuditWriteFailure } from './auditHealth.js'; +import { recordAuthFailure } from './authFailureCounter.js'; type DeprecatedAuthEventType = 'notication_sent' | 'registration_suspicous' | 'request_suspicous'; @@ -67,18 +66,30 @@ export class AuthEventService { userAgent = 'unknown', metadata = null, }: AuthEventContextOptions) { + const normalizedType = normalizeAuthEventType(type); + + // Counted before the audit write and in its own statement, so a trail that + // cannot be written no longer takes the lockout control down with it. This + // used to be derived from auth_events, which meant the control and its + // telemetry shared one failure mode and both failed open. + await recordAuthFailure({ userId, type: normalizedType }); + try { await AuthEvent.create({ user_id: userId, actor_user_id: actorUserId, session_id: sessionId, - type: normalizeAuthEventType(type), + type: normalizedType, ip_address: ipAddress || 'unknown', user_agent: userAgent || 'unknown', metadata: redactMetadata(metadata), }); } catch (err) { - logger.error(`Failed to write AuthEvent: ${err}`); + // Still swallowed: 137 call sites await this, many from inside error + // handlers, and throwing here would turn a bookkeeping failure into a + // failed request. The failure is no longer silent, though. It is reported + // through /health/status so a monitor can act on it. + recordAuditWriteFailure(err); } } diff --git a/src/services/authFailureCounter.ts b/src/services/authFailureCounter.ts new file mode 100644 index 0000000..dd38c5b --- /dev/null +++ b/src/services/authFailureCounter.ts @@ -0,0 +1,88 @@ +/* + * Copyright © 2026 Fells Code, LLC + * Licensed under the GNU Affero General Public License v3.0 + * See LICENSE file in the project root for full license information + */ + +import { Op } from 'sequelize'; + +import { AuthFailure } from '../models/authFailures.js'; +import getLogger from '../utils/logger.js'; +import { recordAuditWriteFailure } from './auditHealth.js'; + +const logger = getLogger('authFailureCounter'); + +/** + * The event types that count towards account lockout. + * + * Kept here rather than in the lockout policy because this is now what decides + * whether an attempt is recorded at all, and the policy only reads the total. + */ +export const LOCKOUT_FAILURE_TYPES = [ + 'login_failed', + 'webauthn_login_failed', + 'verify_otp_failed', + 'totp_failed', + 'magic_link_failed', +]; + +export function isLockoutFailureType(type: string): boolean { + return LOCKOUT_FAILURE_TYPES.includes(type); +} + +/** + * Records a failed attempt against the lockout counter. + * + * A no-op for anything that is not a lockout failure, and for an attempt that + * could not be tied to a user, since lockout is per account. + * + * Does not throw. A counter that cannot be written means an attacker gets one + * extra attempt, which is worse than nothing but far better than failing the + * request; and unlike before, it is reported rather than swallowed, so the + * instance shows degraded instead of quietly under-counting. + */ +export async function recordAuthFailure(params: { + userId: string | null | undefined; + type: string; + occurredAt?: Date; +}): Promise { + const { userId, type } = params; + + if (!userId || !isLockoutFailureType(type)) { + return false; + } + + try { + await AuthFailure.create({ + userId, + type, + occurredAt: params.occurredAt ?? new Date(), + }); + + return true; + } catch (error) { + recordAuditWriteFailure(error); + logger.error(`Failed to record an authentication failure for lockout: ${error}`); + + return false; + } +} + +/** + * How many failures a user has accumulated inside the window. + * + * Throws rather than returning a number it does not have. The caller decides + * what an unknown count means, and for lockout that has to be "assume locked": + * the previous implementation coalesced a failed query to zero, which read as + * not locked and removed the control exactly when the database was unhealthy. + */ +export async function countRecentFailures(userId: string, since: Date): Promise { + const count = await AuthFailure.count({ + where: { + userId, + occurredAt: { [Op.gte]: since }, + }, + }); + + return Number(count); +} diff --git a/src/services/lockoutPolicyService.ts b/src/services/lockoutPolicyService.ts index 43b67e3..bae70eb 100644 --- a/src/services/lockoutPolicyService.ts +++ b/src/services/lockoutPolicyService.ts @@ -5,12 +5,14 @@ */ import { Request, Response } from 'express'; -import { Op } from 'sequelize'; import { getSystemConfig } from '../config/getSystemConfig.js'; -import { AuthEvent } from '../models/authEvents.js'; import type { LockoutPolicy } from '../schemas/systemConfig.schema.js'; +import getLogger from '../utils/logger.js'; import { AuthEventService } from './authEventService.js'; +import { countRecentFailures } from './authFailureCounter.js'; + +const logger = getLogger('lockoutPolicy'); const DEFAULT_LOCKOUT_POLICY: LockoutPolicy = { enabled: true, @@ -19,14 +21,6 @@ const DEFAULT_LOCKOUT_POLICY: LockoutPolicy = { lockoutSeconds: 15 * 60, }; -const LOCKOUT_FAILURE_TYPES = [ - 'login_failed', - 'webauthn_login_failed', - 'verify_otp_failed', - 'totp_failed', - 'magic_link_failed', -]; - async function getLockoutPolicy(): Promise { let configuredPolicy: LockoutPolicy | undefined; @@ -52,26 +46,38 @@ export async function getUserLockoutStatus(userId: string, now = new Date()) { failureCount: 0, retryAfterSeconds: 0, policy, + countUnavailable: false, }; } const windowStart = new Date(now.getTime() - policy.windowSeconds * 1000); - const failureCount = - Number( - await AuthEvent.count({ - where: { - user_id: userId, - type: { [Op.in]: LOCKOUT_FAILURE_TYPES }, - created_at: { [Op.gte]: windowStart }, - }, - }), - ) || 0; + + let failureCount: number; + + try { + failureCount = await countRecentFailures(userId, windowStart); + } catch (error) { + // Fail closed. This used to coalesce a failed query to zero, which read as + // not locked, so the brute force protection came off exactly when the + // database was unhealthy. Refusing an authentication we cannot vouch for is + // the lesser harm, and the caller sees the same 423 a locked account gets. + logger.error(`Could not read the lockout counter, treating the account as locked: ${error}`); + + return { + locked: true, + failureCount: policy.maxFailures, + retryAfterSeconds: policy.lockoutSeconds, + policy, + countUnavailable: true, + }; + } return { locked: failureCount >= policy.maxFailures, failureCount, retryAfterSeconds: policy.lockoutSeconds, policy, + countUnavailable: false, }; } diff --git a/tests/integration/authentication/authentication.spec.ts b/tests/integration/authentication/authentication.spec.ts index a0659d2..dfe7288 100644 --- a/tests/integration/authentication/authentication.spec.ts +++ b/tests/integration/authentication/authentication.spec.ts @@ -20,6 +20,7 @@ import { revokeSessionChain, } from '../../../src/services/sessionService'; import { AuthEvent } from '../../../src/models/authEvents'; +import { AuthFailure } from '../../../src/models/authFailures'; import { logoutCurrentSession } from '../../../src/controllers/authentication'; let app: Application; @@ -291,7 +292,7 @@ describe('POST /login', () => { it('rejects login for a locked account', async () => { (User.findOne as any).mockResolvedValue(buildUser({ verified: true })); - (AuthEvent.count as any).mockResolvedValue(10); + (AuthFailure.count as any).mockResolvedValue(10); (getSystemConfig as any).mockResolvedValue({ lockout_policy: { enabled: true, maxFailures: 10, windowSeconds: 900, lockoutSeconds: 900 }, }); diff --git a/tests/integration/health/health.spec.ts b/tests/integration/health/health.spec.ts index b157b6e..fbda3f4 100644 --- a/tests/integration/health/health.spec.ts +++ b/tests/integration/health/health.spec.ts @@ -3,6 +3,10 @@ import { createApp } from '../../../src/app'; import { beforeAll, beforeEach, describe, expect, it, vi } from 'vitest'; import { Application } from 'express'; +import { + recordAuditWriteFailure, + resetAuditHealthForTests, +} from '../../../src/services/auditHealth.js'; import { AuthEventService } from '../../../src/services/authEventService.js'; let app: Application; @@ -13,6 +17,7 @@ beforeAll(async () => { beforeEach(() => { vi.clearAllMocks(); + resetAuditHealthForTests(); }); describe('Health Routes', () => { @@ -20,9 +25,26 @@ describe('Health Routes', () => { const res = await request(app).get('/health/status'); expect(res.status).toBe(200); + // The healthy body is unchanged, so anything already parsing it is unaffected. expect(res.body).toEqual({ message: 'System up' }); }); + // NIST 800-53 AU-5 wants a defined action when audit logging fails. Reporting + // it where monitoring already looks is that action; a log line nobody reads is + // not. + it('reports degraded when audit writes are failing', async () => { + recordAuditWriteFailure(new Error('disk full')); + + const res = await request(app).get('/health/status'); + + // Still 200: the service is serving requests and should not be pulled out of + // a load balancer for this. + expect(res.status).toBe(200); + expect(res.body.message).toBe('System up, audit degraded'); + expect(res.body.degraded.audit.failureCount).toBe(1); + expect(res.body.degraded.audit.lastFailureAt).toEqual(expect.any(String)); + }); + it('returns the API version', async () => { const res = await request(app).get('/health/version'); diff --git a/tests/integration/webauthn/webauthn.spec.ts b/tests/integration/webauthn/webauthn.spec.ts index 6b9fc6c..81e9174 100644 --- a/tests/integration/webauthn/webauthn.spec.ts +++ b/tests/integration/webauthn/webauthn.spec.ts @@ -15,6 +15,7 @@ import { buildWebAuthnChallenge } from '../../factories/webauthnChallengeFactory import { buildCredential } from '../../factories/credentialFactory'; import { generateRefreshToken, hashRefreshToken, signAccessToken } from '../../../src/lib/token'; import { AuthEvent } from '../../../src/models/authEvents'; +import { AuthFailure } from '../../../src/models/authFailures'; import { AuthEventService } from '../../../src/services/authEventService'; import { generateWebAuthn, @@ -1233,7 +1234,7 @@ describe('POST /webauthn/login/finish', () => { }); it('returns 423 when the account is locked', async () => { - (AuthEvent.count as any).mockResolvedValue(10); + (AuthFailure.count as any).mockResolvedValue(10); (getSystemConfig as any).mockResolvedValue({ lockout_policy: { enabled: true, diff --git a/tests/setup/mocks.ts b/tests/setup/mocks.ts index 7bbca91..3c3959a 100644 --- a/tests/setup/mocks.ts +++ b/tests/setup/mocks.ts @@ -34,6 +34,17 @@ vi.mock('../../src/models/systemConfig.js', () => ({ }, })); +vi.mock('../../src/models/authFailures.js', () => ({ + AuthFailure: { + create: vi.fn(), + // Defaults to zero so the shared mock user is not locked out. A spec that + // exercises lockout sets its own value, and a spec that makes this reject is + // exercising the fail-closed path deliberately. + count: vi.fn(() => Promise.resolve(0)), + destroy: vi.fn(), + }, +})); + vi.mock('../../src/models/credentials.js', () => ({ Credential: { findAll: vi.fn(), diff --git a/tests/unit/models/models.spec.ts b/tests/unit/models/models.spec.ts index 9f332e2..5d34bcc 100644 --- a/tests/unit/models/models.spec.ts +++ b/tests/unit/models/models.spec.ts @@ -1,6 +1,7 @@ import { describe, it, expect, vi, beforeEach } from 'vitest'; vi.unmock('../../../src/models/authEvents.js'); +vi.unmock('../../../src/models/authFailures.js'); vi.unmock('../../../src/models/sessions.js'); vi.unmock('../../../src/models/users.js'); vi.unmock('../../../src/models/systemConfig.js'); diff --git a/tests/unit/services/auditHealth.spec.ts b/tests/unit/services/auditHealth.spec.ts new file mode 100644 index 0000000..ac05182 --- /dev/null +++ b/tests/unit/services/auditHealth.spec.ts @@ -0,0 +1,62 @@ +import { beforeEach, describe, expect, it } from 'vitest'; + +import { + AUDIT_DEGRADED_WINDOW_MS, + getAuditHealth, + recordAuditWriteFailure, + resetAuditHealthForTests, +} from '../../../src/services/auditHealth.js'; + +const NOW = new Date('2026-08-31T12:00:00.000Z'); + +beforeEach(() => { + resetAuditHealthForTests(); +}); + +describe('auditHealth', () => { + it('is healthy before anything has failed', () => { + expect(getAuditHealth(NOW)).toEqual({ + degraded: false, + failureCount: 0, + lastFailureAt: null, + }); + }); + + it('reports degraded after a write failure', () => { + recordAuditWriteFailure(new Error('disk full'), NOW); + + expect(getAuditHealth(NOW)).toEqual({ + degraded: true, + failureCount: 1, + lastFailureAt: NOW.toISOString(), + }); + }); + + it('counts repeated failures', () => { + recordAuditWriteFailure(new Error('one'), NOW); + recordAuditWriteFailure(new Error('two'), NOW); + + expect(getAuditHealth(NOW).failureCount).toBe(2); + }); + + // An instance that recovers should stop claiming to be degraded on its own, + // rather than needing a restart to clear the flag. + it('recovers once the window has passed', () => { + recordAuditWriteFailure(new Error('transient'), NOW); + + const afterWindow = new Date(NOW.getTime() + AUDIT_DEGRADED_WINDOW_MS + 1); + + expect(getAuditHealth(afterWindow).degraded).toBe(false); + // The total is still visible, so a recovered instance does not hide that it + // lost events. + expect(getAuditHealth(afterWindow).failureCount).toBe(1); + }); + + it('stays degraded inside the window', () => { + recordAuditWriteFailure(new Error('transient'), NOW); + + const insideWindow = new Date(NOW.getTime() + AUDIT_DEGRADED_WINDOW_MS - 1); + + expect(getAuditHealth(insideWindow).degraded).toBe(true); + }); +}); diff --git a/tests/unit/services/authEventService.spec.ts b/tests/unit/services/authEventService.spec.ts index da9fddd..9f1a28a 100644 --- a/tests/unit/services/authEventService.spec.ts +++ b/tests/unit/services/authEventService.spec.ts @@ -75,23 +75,24 @@ describe('AuthEventService', () => { ); }); - it('swallows errors and logs failure', async () => { + // Still swallowed: 137 call sites await this, many from inside error handlers, + // so throwing would turn a bookkeeping failure into a failed request. It is no + // longer silent, though, which is the part NIST 800-53 AU-5 asks for. + it('swallows a failed write but reports the instance as degraded', async () => { const { AuthEvent } = await import('../../../src/models/authEvents.js'); - const getLogger = (await import('../../../src/utils/logger.js')).default; - + const { getAuditHealth, resetAuditHealthForTests } = + await import('../../../src/services/auditHealth.js'); const { AuthEventService } = await import('../../../src/services/authEventService.js'); + resetAuditHealthForTests(); (AuthEvent.create as any).mockRejectedValue(new Error('fail')); - const req = buildReq(); - - await AuthEventService.log({ - type: 'login_success', - req, - }); + await expect( + AuthEventService.log({ type: 'login_success', req: buildReq() }), + ).resolves.toBeUndefined(); - expect(getLogger).toHaveBeenCalledWith('authEventService'); - expect(getLogger.mock.results[0]?.value.error).toHaveBeenCalled(); + expect(getAuditHealth().degraded).toBe(true); + expect(getAuditHealth().failureCount).toBe(1); }); it('loginSuccess calls log', async () => { diff --git a/tests/unit/services/authFailureCounter.spec.ts b/tests/unit/services/authFailureCounter.spec.ts new file mode 100644 index 0000000..fa2e046 --- /dev/null +++ b/tests/unit/services/authFailureCounter.spec.ts @@ -0,0 +1,89 @@ +import { beforeEach, describe, expect, it, vi } from 'vitest'; + +import { AuthFailure } from '../../../src/models/authFailures.js'; +import { getAuditHealth, resetAuditHealthForTests } from '../../../src/services/auditHealth.js'; +import { + countRecentFailures, + isLockoutFailureType, + recordAuthFailure, +} from '../../../src/services/authFailureCounter.js'; + +beforeEach(() => { + resetAuditHealthForTests(); + (AuthFailure.create as any).mockResolvedValue({}); + (AuthFailure.count as any).mockResolvedValue(0); +}); + +describe('recordAuthFailure', () => { + it('records a failure that counts towards lockout', async () => { + const occurredAt = new Date('2026-08-31T00:00:00.000Z'); + + await expect( + recordAuthFailure({ userId: 'user-1', type: 'login_failed', occurredAt }), + ).resolves.toBe(true); + + expect(AuthFailure.create).toHaveBeenCalledWith({ + userId: 'user-1', + type: 'login_failed', + occurredAt, + }); + }); + + it.each(['login_success', 'registration_failed', 'informational'])( + 'ignores %s, which lockout does not count', + async (type) => { + await expect(recordAuthFailure({ userId: 'user-1', type })).resolves.toBe(false); + expect(AuthFailure.create).not.toHaveBeenCalled(); + }, + ); + + // Lockout is per account, so a failure that could not be tied to one has + // nothing to count against. + it.each([[null], [undefined], ['']])('ignores an attempt with no user (%s)', async (userId) => { + await expect( + recordAuthFailure({ userId: userId as string | null, type: 'login_failed' }), + ).resolves.toBe(false); + expect(AuthFailure.create).not.toHaveBeenCalled(); + }); + + // An attacker gets one extra attempt, which beats failing the request, but it + // is reported rather than swallowed the way the audit write used to be. + it('reports degraded rather than throwing when the counter cannot be written', async () => { + (AuthFailure.create as any).mockRejectedValue(new Error('disk full')); + + await expect(recordAuthFailure({ userId: 'user-1', type: 'login_failed' })).resolves.toBe( + false, + ); + expect(getAuditHealth().degraded).toBe(true); + }); +}); + +describe('countRecentFailures', () => { + it('counts a user inside the window', async () => { + (AuthFailure.count as any).mockResolvedValue(4); + const since = new Date('2026-08-31T00:00:00.000Z'); + + await expect(countRecentFailures('user-1', since)).resolves.toBe(4); + expect(AuthFailure.count).toHaveBeenCalledWith( + expect.objectContaining({ where: expect.objectContaining({ userId: 'user-1' }) }), + ); + }); + + // The caller decides what an unknown count means. Returning a number here would + // be inventing one, which is exactly how the old `|| 0` removed the control. + it('propagates a failed query instead of coalescing it to zero', async () => { + (AuthFailure.count as any).mockRejectedValue(new Error('connection pool exhausted')); + + await expect(countRecentFailures('user-1', new Date())).rejects.toThrow( + 'connection pool exhausted', + ); + }); +}); + +describe('isLockoutFailureType', () => { + it('recognises the types that count', () => { + expect(isLockoutFailureType('totp_failed')).toBe(true); + expect(isLockoutFailureType('magic_link_failed')).toBe(true); + expect(isLockoutFailureType('login_success')).toBe(false); + }); +}); diff --git a/tests/unit/services/lockoutPolicyService.spec.ts b/tests/unit/services/lockoutPolicyService.spec.ts index c2d9700..a5c20fd 100644 --- a/tests/unit/services/lockoutPolicyService.spec.ts +++ b/tests/unit/services/lockoutPolicyService.spec.ts @@ -4,10 +4,8 @@ vi.mock('../../../src/config/getSystemConfig.js', () => ({ getSystemConfig: vi.fn(), })); -vi.mock('../../../src/models/authEvents.js', () => ({ - AuthEvent: { - count: vi.fn(), - }, +vi.mock('../../../src/services/authFailureCounter.js', () => ({ + countRecentFailures: vi.fn(), })); vi.mock('../../../src/services/authEventService.js', () => ({ @@ -17,8 +15,8 @@ vi.mock('../../../src/services/authEventService.js', () => ({ })); import { getSystemConfig } from '../../../src/config/getSystemConfig.js'; -import { AuthEvent } from '../../../src/models/authEvents.js'; import { AuthEventService } from '../../../src/services/authEventService.js'; +import { countRecentFailures } from '../../../src/services/authFailureCounter.js'; import { getUserLockoutStatus, rejectIfUserLocked, @@ -46,14 +44,15 @@ describe('lockoutPolicyService', () => { locked: false, failureCount: 0, retryAfterSeconds: 0, + countUnavailable: false, policy: expect.objectContaining({ enabled: false }), }); - expect(AuthEvent.count).not.toHaveBeenCalled(); + expect(countRecentFailures).not.toHaveBeenCalled(); }); it('falls back to the default policy when config lookup fails', async () => { (getSystemConfig as any).mockRejectedValue(new Error('config unavailable')); - (AuthEvent.count as any).mockResolvedValue(10); + (countRecentFailures as any).mockResolvedValue(10); await expect(getUserLockoutStatus('user-1')).resolves.toEqual( expect.objectContaining({ @@ -65,7 +64,7 @@ describe('lockoutPolicyService', () => { }); it('does nothing when the account is not locked', async () => { - (AuthEvent.count as any).mockResolvedValue(0); + (countRecentFailures as any).mockResolvedValue(0); const req = { ip: '127.0.0.1', headers: {} } as any; const res = { status: vi.fn().mockReturnThis(), json: vi.fn().mockReturnThis() } as any; @@ -76,7 +75,7 @@ describe('lockoutPolicyService', () => { }); it('reports unlocked when failures are below the configured threshold', async () => { - (AuthEvent.count as any).mockResolvedValue(2); + (countRecentFailures as any).mockResolvedValue(2); await expect(getUserLockoutStatus('user-1')).resolves.toEqual( expect.objectContaining({ @@ -87,7 +86,7 @@ describe('lockoutPolicyService', () => { }); it('reports locked when failures meet the configured threshold', async () => { - (AuthEvent.count as any).mockResolvedValue(3); + (countRecentFailures as any).mockResolvedValue(3); await expect(getUserLockoutStatus('user-1')).resolves.toEqual( expect.objectContaining({ @@ -99,7 +98,7 @@ describe('lockoutPolicyService', () => { }); it('returns a lockout response and audit event when active', async () => { - (AuthEvent.count as any).mockResolvedValue(3); + (countRecentFailures as any).mockResolvedValue(3); const req = { ip: '127.0.0.1', @@ -126,4 +125,26 @@ describe('lockoutPolicyService', () => { }), ); }); + + // The advisory: the count used to coalesce a failed query to zero, which read + // as not locked, so brute force protection came off exactly when the database + // was unhealthy. An unknown count now means locked. + it('treats the account as locked when the counter cannot be read', async () => { + (countRecentFailures as any).mockRejectedValue(new Error('connection pool exhausted')); + + const status = await getUserLockoutStatus('user-1'); + + expect(status.locked).toBe(true); + expect(status.countUnavailable).toBe(true); + }); + + it('refuses the request when the counter cannot be read', async () => { + (countRecentFailures as any).mockRejectedValue(new Error('table is locked')); + const res: any = { status: vi.fn().mockReturnThis(), json: vi.fn().mockReturnThis() }; + + await expect(rejectIfUserLocked({ userId: 'user-1', req: {} as never, res })).resolves.toBe( + true, + ); + expect(res.status).toHaveBeenCalledWith(423); + }); });