diff --git a/src/middleware/logging.ts b/src/middleware/logging.ts index 87c180d..f9b447c 100644 --- a/src/middleware/logging.ts +++ b/src/middleware/logging.ts @@ -12,9 +12,26 @@ interface FileNotFoundParams { fileId: string; } +interface AuthLockoutTriggeredParams extends AuthLogParams { + durationSeconds: number; +} + +interface AuthLockedAttemptParams extends AuthLogParams { + retryAfterSeconds: number; +} + +interface AuthRateLimitedParams { + ip: string; + userAgent: string; + route: string; +} + export interface Logger { authSuccess(params: AuthLogParams): Promise; authFailure(params: AuthLogParams): Promise; + authLockoutTriggered(params: AuthLockoutTriggeredParams): Promise; + authLockedAttempt(params: AuthLockedAttemptParams): Promise; + authRateLimited(params: AuthRateLimitedParams): Promise; fileNotFound(params: FileNotFoundParams): Promise; } @@ -34,6 +51,12 @@ export function createLogger(logFile: string): Logger { return { authSuccess: (params) => write(authLine('AUTH_SUCCESS', params)), authFailure: (params) => write(authLine('AUTH_FAILURE', params)), + authLockoutTriggered: ({ durationSeconds, ...auth }) => + write(`${authLine('AUTH_LOCKOUT_TRIGGERED', auth)} duration_seconds=${durationSeconds}`), + authLockedAttempt: ({ retryAfterSeconds, ...auth }) => + write(`${authLine('AUTH_LOCKED_ATTEMPT', auth)} retry_after_seconds=${retryAfterSeconds}`), + authRateLimited: ({ ip, userAgent, route }) => + write(`[${timestamp()}] AUTH_RATE_LIMITED ip=${ip} user-agent="${userAgent}" route="${route}"`), fileNotFound: ({ ip, userAgent, fileId }) => write(`[${timestamp()}] FILE_NOT_FOUND ip=${ip} user-agent="${userAgent}" file_id="${fileId}"`), }; diff --git a/src/services/login-handler.ts b/src/services/login-handler.ts new file mode 100644 index 0000000..404d745 --- /dev/null +++ b/src/services/login-handler.ts @@ -0,0 +1,90 @@ +import type Database from 'better-sqlite3'; +import type { Config } from '../config.ts'; +import type { Logger } from '../middleware/logging.ts'; +import type { LockoutService } from './lockout.ts'; +import { getUserByUsername } from '../db/users.ts'; +import { verifyPassword } from './auth.ts'; +import { verifyAgainstDummy } from './dummy-hash.ts'; + +interface UserRow { + id: number; + username: string; + password_hash: string; + created_at: string; +} + +export type LoginResult = + | { kind: 'success'; user: UserRow } + | { kind: 'bad_credentials' } + | { kind: 'locked'; retryAfterSeconds: number } + | { kind: 'bad_request' }; + +export interface LoginHandlerDeps { + db: Database.Database; + config: Config; + logger: Logger; + lockout: LockoutService; +} + +export interface LoginInput { + username: string; + password: string; + ip: string; + userAgent: string; +} + +function canonicalize(username: string): string { + return username.trim().toLowerCase(); +} + +async function clamp(startMs: number, minMs: number): Promise { + const elapsed = Date.now() - startMs; + const remaining = minMs - elapsed; + if (remaining > 0) { + await new Promise((resolve) => setTimeout(resolve, remaining)); + } +} + +export async function attemptLogin( + deps: LoginHandlerDeps, + input: LoginInput, +): Promise { + const { db, config, logger, lockout } = deps; + const start = Date.now(); + + if (!input.username || !input.password) { + // No clamp on bad_request — it's a programmer/format error from the caller, + // not a credential test, so timing isn't sensitive. + return { kind: 'bad_request' }; + } + + const username = canonicalize(input.username); + const logBase = { ip: input.ip, userAgent: input.userAgent, username }; + + const lockStatus = lockout.check(username); + if (lockStatus.locked) { + await logger.authLockedAttempt({ ...logBase, retryAfterSeconds: lockStatus.retryAfterSeconds! }); + await clamp(start, config.loginMinResponseMs); + return { kind: 'locked', retryAfterSeconds: lockStatus.retryAfterSeconds! }; + } + + const user = getUserByUsername(db, username); + const valid = user + ? await verifyPassword(input.password, user.password_hash) + : await verifyAgainstDummy(input.password); + + if (user && valid) { + lockout.recordSuccess(username); + await logger.authSuccess(logBase); + await clamp(start, config.loginMinResponseMs); + return { kind: 'success', user }; + } + + const failure = lockout.recordFailure(username); + if (failure.locked) { + await logger.authLockoutTriggered({ ...logBase, durationSeconds: failure.durationSeconds }); + } + await logger.authFailure(logBase); + await clamp(start, config.loginMinResponseMs); + return { kind: 'bad_credentials' }; +} diff --git a/tests/unit/dummy-hash.test.ts b/tests/unit/dummy-hash.test.ts new file mode 100644 index 0000000..6387f8f --- /dev/null +++ b/tests/unit/dummy-hash.test.ts @@ -0,0 +1,58 @@ +import { describe, it, expect, beforeEach } from 'vitest'; +import bcrypt from 'bcrypt'; +import { verifyAgainstDummy, _resetDummyHashForTests } from '../../src/services/dummy-hash.ts'; +import { hashPassword, verifyPassword } from '../../src/services/auth.ts'; + +describe('dummy hash', () => { + beforeEach(() => { + _resetDummyHashForTests(); + }); + + it('always returns false', async () => { + expect(await verifyAgainstDummy('whatever')).toBe(false); + expect(await verifyAgainstDummy('')).toBe(false); + expect(await verifyAgainstDummy('admin')).toBe(false); + }); + + it('takes comparable time to verifying a real bcrypt hash (within 5x)', async () => { + // Warm dummy hash so the cache is hot. + await verifyAgainstDummy('warmup'); + const realHash = await hashPassword('actual-password'); + + const start1 = Date.now(); + await verifyPassword('actual-password', realHash); + const realMs = Date.now() - start1; + + const start2 = Date.now(); + await verifyAgainstDummy('any-password'); + const dummyMs = Date.now() - start2; + + // Both should be in the same ballpark — bcrypt cost factor is the same. + // Generous bound to avoid flakes on slow CI. + expect(dummyMs).toBeGreaterThan(realMs / 5); + expect(dummyMs).toBeLessThan(realMs * 5); + }, 10_000); + + it('memoizes the dummy hash across calls', async () => { + // First call computes, subsequent calls reuse — covered by cache hit + // being noticeably faster than a fresh hash. Just assert the function + // is callable repeatedly without error. + await verifyAgainstDummy('a'); + await verifyAgainstDummy('b'); + await verifyAgainstDummy('c'); + expect(true).toBe(true); + }); + + it('runs a real bcrypt comparison (does not short-circuit)', async () => { + // Spy by counting bcrypt.compare calls would be nice, but bcrypt + // is a compiled module. Indirect check: the call must actually take + // bcrypt-comparison time after warmup. + await verifyAgainstDummy('warmup'); + const start = Date.now(); + await verifyAgainstDummy('test'); + const elapsed = Date.now() - start; + // bcrypt 12 rounds takes >50ms on any modern CPU + expect(elapsed).toBeGreaterThan(20); + expect(bcrypt).toBeDefined(); + }, 10_000); +}); diff --git a/tests/unit/logging.test.ts b/tests/unit/logging.test.ts index 97cdd1d..9a14e74 100644 --- a/tests/unit/logging.test.ts +++ b/tests/unit/logging.test.ts @@ -50,6 +50,48 @@ describe('middleware/logging', () => { expect(existsSync(logFile)).toBe(true); }); + it('writes AUTH_LOCKOUT_TRIGGERED log entry with duration', async () => { + const logger = createLogger(logFile); + await logger.authLockoutTriggered({ + ip: '1.2.3.4', + userAgent: 'TestAgent/1.0', + username: 'alice', + durationSeconds: 60, + }); + const content = readFileSync(logFile, 'utf-8'); + expect(content).toMatch(/AUTH_LOCKOUT_TRIGGERED/); + expect(content).toMatch(/ip=1\.2\.3\.4/); + expect(content).toMatch(/username="alice"/); + expect(content).toMatch(/duration_seconds=60/); + }); + + it('writes AUTH_LOCKED_ATTEMPT log entry with retry-after', async () => { + const logger = createLogger(logFile); + await logger.authLockedAttempt({ + ip: '1.2.3.4', + userAgent: 'TestAgent/1.0', + username: 'alice', + retryAfterSeconds: 25, + }); + const content = readFileSync(logFile, 'utf-8'); + expect(content).toMatch(/AUTH_LOCKED_ATTEMPT/); + expect(content).toMatch(/username="alice"/); + expect(content).toMatch(/retry_after_seconds=25/); + }); + + it('writes AUTH_RATE_LIMITED log entry with route', async () => { + const logger = createLogger(logFile); + await logger.authRateLimited({ + ip: '9.9.9.9', + userAgent: 'curl/7.0', + route: '/api/v1/auth/login', + }); + const content = readFileSync(logFile, 'utf-8'); + expect(content).toMatch(/AUTH_RATE_LIMITED/); + expect(content).toMatch(/ip=9\.9\.9\.9/); + expect(content).toMatch(/route="\/api\/v1\/auth\/login"/); + }); + it('appends multiple entries', async () => { const logger = createLogger(logFile); await logger.authSuccess({ ip: '1.1.1.1', userAgent: 'a', username: 'u1' }); diff --git a/tests/unit/login-handler.test.ts b/tests/unit/login-handler.test.ts new file mode 100644 index 0000000..db9ca90 --- /dev/null +++ b/tests/unit/login-handler.test.ts @@ -0,0 +1,212 @@ +import { describe, it, expect, beforeEach, vi } from 'vitest'; +import { mkdtempSync, rmSync, readFileSync } from 'fs'; +import { tmpdir } from 'os'; +import { join } from 'path'; +import type Database from 'better-sqlite3'; +import { initDb } from '../../src/db/schema.ts'; +import { createUser } from '../../src/db/users.ts'; +import { hashPassword } from '../../src/services/auth.ts'; +import { createLogger } from '../../src/middleware/logging.ts'; +import { createLockoutService } from '../../src/services/lockout.ts'; +import { attemptLogin } from '../../src/services/login-handler.ts'; +import { _resetDummyHashForTests } from '../../src/services/dummy-hash.ts'; +import type { Config } from '../../src/config.ts'; + +function makeConfig(overrides: Partial = {}): Config { + return { + port: 0, + host: '127.0.0.1', + jwtSecret: 'x', + jwtExpiry: '1h', + dbPath: ':memory:', + uploadDir: '/tmp', + logFile: '/tmp/x.log', + maxFileSize: 0, + baseUrl: '', + cookieSecure: false, + trustProxy: false, + lockoutThreshold: 2, + lockoutBaseSeconds: 60, + lockoutMaxSeconds: 600, + loginMinResponseMs: 50, + loginRateLimitMax: 0, + loginRateLimitWindowSeconds: 0, + ...overrides, + }; +} + +describe('login handler', () => { + let db: Database.Database; + let logDir: string; + let logFile: string; + let config: Config; + + beforeEach(async () => { + _resetDummyHashForTests(); + db = initDb(':memory:'); + logDir = mkdtempSync(join(tmpdir(), 'nanodrop-handler-')); + logFile = join(logDir, 'test.log'); + config = makeConfig({ logFile }); + const passwordHash = await hashPassword('correct-pw'); + createUser(db, { username: 'alice', passwordHash }); + // Warm dummy hash so timing assertions don't include the first cold compute. + const { verifyAgainstDummy } = await import('../../src/services/dummy-hash.ts'); + await verifyAgainstDummy('warmup'); + }); + + function buildDeps() { + const logger = createLogger(logFile); + const lockout = createLockoutService({ db, config }); + return { db, config, logger, lockout }; + } + + it('returns success for valid credentials and resets lockout', async () => { + const deps = buildDeps(); + const result = await attemptLogin(deps, { + username: 'alice', + password: 'correct-pw', + ip: '1.1.1.1', + userAgent: 'ua', + }); + expect(result.kind).toBe('success'); + if (result.kind === 'success') { + expect(result.user.username).toBe('alice'); + } + const log = readFileSync(logFile, 'utf-8'); + expect(log).toMatch(/AUTH_SUCCESS/); + }); + + it('returns bad_credentials and logs failure on wrong password', async () => { + const deps = buildDeps(); + const result = await attemptLogin(deps, { + username: 'alice', + password: 'wrong', + ip: '1.1.1.1', + userAgent: 'ua', + }); + expect(result.kind).toBe('bad_credentials'); + const log = readFileSync(logFile, 'utf-8'); + expect(log).toMatch(/AUTH_FAILURE/); + expect(log).toMatch(/username="alice"/); + }); + + it('returns bad_credentials for unknown user (still runs bcrypt against dummy)', async () => { + const deps = buildDeps(); + const start = Date.now(); + const result = await attemptLogin(deps, { + username: 'ghost', + password: 'whatever', + ip: '1.1.1.1', + userAgent: 'ua', + }); + const elapsed = Date.now() - start; + expect(result.kind).toBe('bad_credentials'); + // Must spend bcrypt-comparable time even for unknown user. + expect(elapsed).toBeGreaterThan(20); + const log = readFileSync(logFile, 'utf-8'); + expect(log).toMatch(/AUTH_FAILURE/); + expect(log).toMatch(/username="ghost"/); + }, 10_000); + + it('canonicalizes username (lowercase + trim) before lookup and lockout', async () => { + const deps = buildDeps(); + const result = await attemptLogin(deps, { + username: ' ALICE ', + password: 'correct-pw', + ip: '1.1.1.1', + userAgent: 'ua', + }); + expect(result.kind).toBe('success'); + }); + + it('returns bad_request when username or password is empty', async () => { + const deps = buildDeps(); + const r1 = await attemptLogin(deps, { username: '', password: 'x', ip: '1', userAgent: 'ua' }); + expect(r1.kind).toBe('bad_request'); + const r2 = await attemptLogin(deps, { username: 'alice', password: '', ip: '1', userAgent: 'ua' }); + expect(r2.kind).toBe('bad_request'); + }); + + it('triggers lockout at threshold and logs AUTH_LOCKOUT_TRIGGERED', async () => { + const deps = buildDeps(); + await attemptLogin(deps, { username: 'alice', password: 'wrong', ip: '1.1.1.1', userAgent: 'ua' }); + const second = await attemptLogin(deps, { username: 'alice', password: 'wrong', ip: '1.1.1.1', userAgent: 'ua' }); + expect(second.kind).toBe('bad_credentials'); + const log = readFileSync(logFile, 'utf-8'); + expect(log).toMatch(/AUTH_LOCKOUT_TRIGGERED/); + expect(log).toMatch(/duration_seconds=60/); + }); + + it('returns locked + retry-after on subsequent attempt; correct password still rejected', async () => { + const deps = buildDeps(); + await attemptLogin(deps, { username: 'alice', password: 'wrong', ip: '1.1.1.1', userAgent: 'ua' }); + await attemptLogin(deps, { username: 'alice', password: 'wrong', ip: '1.1.1.1', userAgent: 'ua' }); + + const blocked = await attemptLogin(deps, { + username: 'alice', + password: 'correct-pw', + ip: '1.1.1.1', + userAgent: 'ua', + }); + expect(blocked.kind).toBe('locked'); + if (blocked.kind === 'locked') { + expect(blocked.retryAfterSeconds).toBeGreaterThan(0); + expect(blocked.retryAfterSeconds).toBeLessThanOrEqual(60); + } + + const log = readFileSync(logFile, 'utf-8'); + expect(log).toMatch(/AUTH_LOCKED_ATTEMPT/); + // Even though password was correct, no AUTH_SUCCESS for this attempt. + const successCount = (log.match(/AUTH_SUCCESS/g) ?? []).length; + expect(successCount).toBe(0); + }); + + it('does NOT call bcrypt when account is locked (short-circuits)', async () => { + const deps = buildDeps(); + // Lock the account. + await attemptLogin(deps, { username: 'alice', password: 'wrong', ip: '1', userAgent: 'ua' }); + await attemptLogin(deps, { username: 'alice', password: 'wrong', ip: '1', userAgent: 'ua' }); + + // Locked attempt with constant-time clamp at 50ms — should be roughly clamp duration, + // not bcrypt time (250ms+). + const start = Date.now(); + await attemptLogin(deps, { username: 'alice', password: 'correct-pw', ip: '1', userAgent: 'ua' }); + const elapsed = Date.now() - start; + // Clamp is 50ms; allow generous slack but assert well under bcrypt cost. + expect(elapsed).toBeLessThan(150); + }); + + it('respects loginMinResponseMs clamp on bad_credentials', async () => { + config = makeConfig({ logFile, loginMinResponseMs: 200 }); + const deps = buildDeps(); + const start = Date.now(); + await attemptLogin(deps, { username: 'alice', password: 'wrong', ip: '1', userAgent: 'ua' }); + const elapsed = Date.now() - start; + expect(elapsed).toBeGreaterThanOrEqual(190); + }, 10_000); + + it('successful login between failures resets the counter', async () => { + const deps = buildDeps(); + await attemptLogin(deps, { username: 'alice', password: 'wrong', ip: '1', userAgent: 'ua' }); + await attemptLogin(deps, { username: 'alice', password: 'correct-pw', ip: '1', userAgent: 'ua' }); + const r = await attemptLogin(deps, { username: 'alice', password: 'wrong', ip: '1', userAgent: 'ua' }); + // After reset, this is failure #1 — well under threshold of 2, so no lock yet. + expect(r.kind).toBe('bad_credentials'); + // No AUTH_LOCKOUT_TRIGGERED in log. + const log = readFileSync(logFile, 'utf-8'); + expect(log).not.toMatch(/AUTH_LOCKOUT_TRIGGERED/); + }); + + it('unknown username also accumulates lockout', async () => { + const deps = buildDeps(); + await attemptLogin(deps, { username: 'ghost', password: 'x', ip: '1', userAgent: 'ua' }); + await attemptLogin(deps, { username: 'ghost', password: 'x', ip: '1', userAgent: 'ua' }); + const r = await attemptLogin(deps, { username: 'ghost', password: 'x', ip: '1', userAgent: 'ua' }); + expect(r.kind).toBe('locked'); + }, 10_000); + + // Cleanup + beforeEach(() => { + return () => rmSync(logDir, { recursive: true, force: true }); + }); +});