From dbb27d2e262009a77e3bc04e4b915f45ae2c647d Mon Sep 17 00:00:00 2001 From: Martin Obe Date: Tue, 28 Jul 2026 23:28:25 +0100 Subject: [PATCH] Closes #616: Add cursor pagination on /api/audit --- .../0025_audit_logs_cursor_index.sql | 20 ++ package-lock.json | 17 + src/db/schema.ts | 10 +- tests/auditLogCursorStability.test.ts | 294 ++++++++++++++++++ 4 files changed, 340 insertions(+), 1 deletion(-) create mode 100644 drizzle/migrations/0025_audit_logs_cursor_index.sql create mode 100644 tests/auditLogCursorStability.test.ts diff --git a/drizzle/migrations/0025_audit_logs_cursor_index.sql b/drizzle/migrations/0025_audit_logs_cursor_index.sql new file mode 100644 index 00000000..91390e85 --- /dev/null +++ b/drizzle/migrations/0025_audit_logs_cursor_index.sql @@ -0,0 +1,20 @@ +-- Migration: 0025_audit_logs_cursor_index +-- Replaces the single-column audit_logs_created_at_idx with a composite +-- (created_at DESC, id DESC) index so that keyset-cursor pagination on +-- GET /api/admin/audit is stable under concurrent inserts. +-- +-- When two rows share the same created_at timestamp (common under high write +-- concurrency) the previous single-column index left the tie-breaking order +-- non-deterministic, meaning a page boundary could skip or repeat rows. +-- The composite index makes (created_at, id) the canonical sort key, matching +-- the ORDER BY and cursor predicate already used in auditLogRepo.ts. + +-- Drop the old single-column index (no longer needed). +DROP INDEX IF EXISTS audit_logs_created_at_idx; + +-- Create the composite covering index used by the keyset cursor predicate: +-- WHERE (created_at < $cursor_ts) +-- OR (created_at = $cursor_ts AND id < $cursor_id) +-- ORDER BY created_at DESC, id DESC +CREATE INDEX IF NOT EXISTS audit_logs_created_at_id_idx + ON audit_logs (created_at DESC, id DESC); diff --git a/package-lock.json b/package-lock.json index e8380bf9..5ee8e0e6 100644 --- a/package-lock.json +++ b/package-lock.json @@ -98,6 +98,7 @@ "integrity": "sha512-RgHBCvtjbOK2gXSNBNIkNoEc9qoVEtau3hj8gEqKQuL3HZAibKarWFEI3Lfm6EYKkLalOh8eSrj9b+ch9H/VBA==", "dev": true, "license": "MIT", + "peer": true, "dependencies": { "@babel/code-frame": "^7.29.7", "@babel/generator": "^7.29.7", @@ -2482,6 +2483,7 @@ "resolved": "https://registry.npmjs.org/@opentelemetry/api/-/api-1.9.1.tgz", "integrity": "sha512-gLyJlPHPZYdAk1JENA9LeHejZe1Ti77/pTeFm/nMXmQH/HFZlcS/O2XJB+L8fkbrNSqhdtlvjBVjxwUYanNH5Q==", "license": "Apache-2.0", + "peer": true, "engines": { "node": ">=8.0.0" } @@ -2918,6 +2920,7 @@ "integrity": "sha512-EANqOCF9QFyra+4pfxUcX9STKJpCLjMbObVzljIJomAWSnuSIEAvyzEU53GaajbXJEgdh0iEcPL+DGvpUd4k1Q==", "devOptional": true, "license": "MIT", + "peer": true, "dependencies": { "undici-types": "~6.21.0" } @@ -2928,6 +2931,7 @@ "integrity": "sha512-bEPFOaMAHTEP1EzpvHTbmwR8UsFyHSKsRisLIHVMXnpNefSbGA1bD6CVy+qKjGSqmZqNqBDV2azOBo8TgkcVow==", "devOptional": true, "license": "MIT", + "peer": true, "dependencies": { "@types/node": "*", "pg-protocol": "*", @@ -3131,6 +3135,7 @@ "integrity": "sha512-CZ4nMxWwgu1HEEFNkeaCptra9QCtkmKdgf3sWh1rl1trIhmxLilgTV4cwcbQ4wemnT4sWQN8CaKOmdYx+g2gMA==", "dev": true, "license": "MIT", + "peer": true, "dependencies": { "@typescript-eslint/scope-manager": "8.65.0", "@typescript-eslint/types": "8.65.0", @@ -3400,6 +3405,7 @@ "integrity": "sha512-xRQbDb9BnwDafYNn6Vwl839DYVjqXYb1XVGtWAZ1kcDc6iwAL4hg3B1dZlRiuENFeO2H53gFG3in621AdERVAg==", "dev": true, "license": "MIT", + "peer": true, "bin": { "acorn": "bin/acorn" }, @@ -3967,6 +3973,7 @@ "integrity": "sha512-iQxPClE07hETVpbRoX7JXX3v/ZQViCxe/SYCxylRLzdEx1xJAufPptfiOqR8tqiCtmbtMDANKWszzjLu1PMAZQ==", "devOptional": true, "license": "Apache-2.0", + "peer": true, "dependencies": { "bare-path": "^3.0.0" } @@ -4193,6 +4200,7 @@ } ], "license": "MIT", + "peer": true, "dependencies": { "baseline-browser-mapping": "^2.10.44", "caniuse-lite": "^1.0.30001806", @@ -5403,6 +5411,7 @@ "integrity": "sha512-DgZS62aPLXKlnxILS/AYCoRvHaZeXceIzlXPkkGGzJWSow1aEk0lbTlxUSlyjC8jcaKxAdOnTDz+o1JFSBsyjw==", "dev": true, "license": "MIT", + "peer": true, "dependencies": { "@eslint-community/eslint-utils": "^4.8.0", "@eslint-community/regexpp": "^4.12.1", @@ -5668,6 +5677,7 @@ "resolved": "https://registry.npmjs.org/express/-/express-4.22.2.tgz", "integrity": "sha512-IuL+Elrou2ZvCFHs18/CIzy2Nzvo25nZ1/D2eIZlz7c+QUayAcYoiM2BthCjs+EBHVpjYjcuLDAiCWgeIX3X1Q==", "license": "MIT", + "peer": true, "dependencies": { "accepts": "~1.3.8", "array-flatten": "1.1.1", @@ -6723,6 +6733,7 @@ "integrity": "sha512-NIy3oAFp9shda19hy4HK0HRTWKtPJmGdnvywu01nOqNC2vZg+Z+fvJDxpMQA88eb2I9EcafcdjYgsDthnYTvGw==", "dev": true, "license": "MIT", + "peer": true, "dependencies": { "@jest/core": "^29.7.0", "@jest/types": "^29.6.3", @@ -7317,6 +7328,7 @@ "integrity": "sha512-AC/7JofJvZGrrneWNaEnJeOLUx+JlGt7tNa0wZiRPT4MY1wmfKjt2+6O2p2uz2+skll8OZZmJMNqeke7kKbNgQ==", "dev": true, "license": "MIT", + "peer": true, "bin": { "jiti": "lib/jiti-cli.mjs" } @@ -8254,6 +8266,7 @@ "resolved": "https://registry.npmjs.org/pg/-/pg-8.22.0.tgz", "integrity": "sha512-8wih1vVIBMxoUM2oB4soJsD9tDnDpLv4OXBJ+EJzFsvycD+lfyIreC2gGHq78f8jbLLt+bvlPTFdFZfJkOuzAA==", "license": "MIT", + "peer": true, "dependencies": { "pg-connection-string": "^2.14.0", "pg-pool": "^3.14.0", @@ -9818,6 +9831,7 @@ "integrity": "sha512-RvwwcruNjI1ncT5xRakeyS9Lf8lcItv34KD+aif+VH9kduAyfYBipGh12274xtenIPZ119/R9BdTBa8gAwSh0A==", "dev": true, "license": "MIT", + "peer": true, "engines": { "node": ">=12" }, @@ -9979,6 +9993,7 @@ "integrity": "sha512-f0FFpIdcHgn8zcPSbf1dRevwt047YMnaiJM3u2w2RewrB+fob/zePZcrOyQoLMMO7aBIddLcQIEK5dYjkLnGrQ==", "dev": true, "license": "MIT", + "peer": true, "dependencies": { "@cspotcode/source-map-support": "^0.8.0", "@tsconfig/node10": "^1.0.7", @@ -10682,6 +10697,7 @@ "integrity": "sha512-jl1vZzPDinLr9eUt3J/t7V6FgNEw9QjvBPdysz9KfQDD41fQrC2Y4vKQdiaUpFT4bXlb1RHhLpp8wtm6M5TgSw==", "dev": true, "license": "Apache-2.0", + "peer": true, "bin": { "tsc": "bin/tsc", "tsserver": "bin/tsserver" @@ -11097,6 +11113,7 @@ "resolved": "https://registry.npmjs.org/zod/-/zod-3.25.76.tgz", "integrity": "sha512-gzUt/qt81nXsFGKIFcC3YnfEAx5NkunCfnDlvuBSSFS02bcXu4Lmea0AFIUwbLWxWPx3d9p8S5QoaujKcNQxcQ==", "license": "MIT", + "peer": true, "funding": { "url": "https://github.com/sponsors/colinhacks" } diff --git a/src/db/schema.ts b/src/db/schema.ts index 794a3ebb..c62b72e4 100644 --- a/src/db/schema.ts +++ b/src/db/schema.ts @@ -370,7 +370,15 @@ export const auditLogs = pgTable( auditLogsCorrelationIdx: index("audit_logs_correlation_idx").on( t.correlationId, ), - auditLogsCreatedAtIdx: index("audit_logs_created_at_idx").on(t.createdAt), + // Composite index for stable cursor pagination: ORDER BY created_at DESC, id DESC. + // The (created_at, id) compound key is unique and monotone, so a keyset cursor + // over it is stable even when rows with the same timestamp are inserted + // concurrently — the id tie-breaker ensures no row is skipped or duplicated + // across page boundaries. + auditLogsCreatedAtIdIdx: index("audit_logs_created_at_id_idx").on( + t.createdAt, + t.id, + ), }), ); diff --git a/tests/auditLogCursorStability.test.ts b/tests/auditLogCursorStability.test.ts new file mode 100644 index 00000000..5ab01b8e --- /dev/null +++ b/tests/auditLogCursorStability.test.ts @@ -0,0 +1,294 @@ +/** + * auditLogCursorStability.test.ts + * + * Focused tests for stable keyset cursor pagination on GET /api/admin/audit. + * + * The cursor is keyed on (created_at, id) DESC. These tests verify that when + * rows share the same created_at timestamp — the scenario that arises under + * concurrent writes — the id tie-breaker keeps pages gapless and duplicate-free. + */ + +import { getAuditLogs } from "../src/repositories/auditLogRepo"; +import { encodeCursor } from "../src/utils/cursor"; +import { db } from "../src/db"; + +// ── DB Mock ────────────────────────────────────────────────────────────────── + +jest.mock("../src/db", () => { + const queryChain = { + select: jest.fn().mockReturnThis(), + from: jest.fn().mockReturnThis(), + where: jest.fn().mockReturnThis(), + orderBy: jest.fn().mockReturnThis(), + limit: jest.fn(), + }; + return { db: queryChain }; +}); + +const mockDb = db as unknown as { + select: jest.Mock; + from: jest.Mock; + where: jest.Mock; + orderBy: jest.Mock; + limit: jest.Mock; +}; + +// ── Helpers ────────────────────────────────────────────────────────────────── + +function makeRow(id: string, createdAt: Date) { + return { + id, + action: "test.action", + walletAddress: "GADDR", + ip: "127.0.0.1", + correlationId: `corr-${id}`, + rateLimitContext: null, + createdAt, + }; +} + +// ── Tests ──────────────────────────────────────────────────────────────────── + +describe("audit log cursor stability under concurrent writes", () => { + beforeEach(() => { + jest.clearAllMocks(); + }); + + describe("ordering contract: DESC (created_at, id)", () => { + it("uses DESC created_at as the primary sort and DESC id as the tie-breaker", async () => { + mockDb.limit.mockResolvedValue([]); + + await getAuditLogs({}); + + // orderBy must be called once + expect(mockDb.orderBy).toHaveBeenCalledTimes(1); + + // Inspect the arguments passed to orderBy; Drizzle passes SQL objects. + // We assert that exactly two sort expressions are provided. + const orderByArgs = mockDb.orderBy.mock.calls[0]; + expect(orderByArgs).toHaveLength(2); + }); + }); + + describe("first page (no cursor)", () => { + it("returns up to `limit` rows and sets nextCursor when more rows exist", async () => { + const ts = new Date("2026-07-28T10:00:00.000Z"); + // Simulate DB returning limit+1 rows (DB-side look-ahead). + const dbRows = [ + makeRow("id-1", ts), + makeRow("id-2", ts), + makeRow("id-3", ts), + ]; + mockDb.limit.mockResolvedValue(dbRows); + + const result = await getAuditLogs({ limit: 2 }); + + expect(result.data).toHaveLength(2); + expect(result.data[0].id).toBe("id-1"); + expect(result.data[1].id).toBe("id-2"); + expect(result.nextCursor).not.toBeNull(); + }); + + it("returns null nextCursor when all rows fit on one page", async () => { + const ts = new Date("2026-07-28T10:00:00.000Z"); + const dbRows = [makeRow("id-1", ts), makeRow("id-2", ts)]; + mockDb.limit.mockResolvedValue(dbRows); + + const result = await getAuditLogs({ limit: 2 }); + + expect(result.data).toHaveLength(2); + expect(result.nextCursor).toBeNull(); + }); + }); + + describe("cursor encoding / decoding round-trip", () => { + it("encodes the last row's (created_at ISO, id) into the nextCursor", async () => { + const ts = new Date("2026-07-28T10:00:00.000Z"); + const dbRows = [makeRow("id-alpha", ts), makeRow("id-beta", ts)]; + // Two rows returned for limit=1 → hasMore=true. + mockDb.limit.mockResolvedValue(dbRows); + + const result = await getAuditLogs({ limit: 1 }); + + expect(result.nextCursor).not.toBeNull(); + + // The cursor must be the opaque encoding of the last row on the page. + const expectedCursor = encodeCursor({ + sortValue: ts.toISOString(), + id: "id-alpha", + }); + expect(result.nextCursor).toBe(expectedCursor); + }); + + it("encodes the cursor using the ISO representation of createdAt", async () => { + const ts = new Date("2026-07-28T22:00:00.500Z"); // includes sub-second precision + const dbRows = [makeRow("id-x", ts), makeRow("id-y", ts)]; + mockDb.limit.mockResolvedValue(dbRows); + + const result = await getAuditLogs({ limit: 1 }); + + const expectedCursor = encodeCursor({ + sortValue: ts.toISOString(), + id: "id-x", + }); + expect(result.nextCursor).toBe(expectedCursor); + }); + }); + + describe("concurrent-write scenario: rows sharing the same created_at timestamp", () => { + /** + * When N rows are inserted with the same millisecond timestamp (e.g. in + * the same transaction or at high write rate), a single-column ORDER BY + * created_at yields an unstable order that can skip or duplicate rows at + * page boundaries. The (created_at, id) keyset cursor eliminates this. + * + * These tests exercise the predicate branch: + * (created_at = $ts AND id < $cursor_id) + */ + + it("includes the id tie-breaker predicate when cursor lands on a duplicate timestamp", async () => { + const sameTs = new Date("2026-07-28T12:00:00.000Z"); + + // Page 1: rows id-3, id-2 (cursor will point at id-2 after page 1). + const page1Rows = [ + makeRow("id-3", sameTs), + makeRow("id-2", sameTs), + makeRow("id-1", sameTs), // look-ahead row → hasMore=true + ]; + mockDb.limit.mockResolvedValueOnce(page1Rows); + + const page1 = await getAuditLogs({ limit: 2 }); + expect(page1.data).toHaveLength(2); + expect(page1.nextCursor).not.toBeNull(); + + // Page 2: simulate fetching the next page using the cursor. + // The cursor points at (sameTs, "id-2"). + // Expect the WHERE clause to include the tie-breaker predicate. + const page2DbRows = [makeRow("id-1", sameTs)]; + mockDb.limit.mockResolvedValueOnce(page2DbRows); + + const page2 = await getAuditLogs({ limit: 2, cursor: page1.nextCursor! }); + + expect(page2.data).toHaveLength(1); + expect(page2.data[0].id).toBe("id-1"); + expect(page2.nextCursor).toBeNull(); + + // The WHERE clause passed to the second query must contain the cursor predicate. + const whereArg = mockDb.where.mock.calls[1][0]; // second call to .where() + expect(whereArg).toBeDefined(); + }); + + it("produces no duplicate rows across two pages of same-timestamp rows", async () => { + const sameTs = new Date("2026-07-28T12:00:00.000Z"); + + // Build 5 rows all with the same timestamp, ordered desc by id. + const allRows = ["e", "d", "c", "b", "a"].map((id) => + makeRow(id, sameTs), + ); + + // Page 1: DB returns first 3 (limit=2, +1 look-ahead). + mockDb.limit.mockResolvedValueOnce(allRows.slice(0, 3)); + const page1 = await getAuditLogs({ limit: 2 }); + + expect(page1.data.map((r) => r.id)).toEqual(["e", "d"]); + expect(page1.nextCursor).not.toBeNull(); + + // Page 2: DB returns remaining rows after the cursor. + mockDb.limit.mockResolvedValueOnce(allRows.slice(2)); // ["c","b","a"] + const page2 = await getAuditLogs({ limit: 2, cursor: page1.nextCursor! }); + + expect(page2.data.map((r) => r.id)).toEqual(["c", "b"]); + expect(page2.nextCursor).not.toBeNull(); + + // Page 3: last row. + mockDb.limit.mockResolvedValueOnce([allRows[4]]); + const page3 = await getAuditLogs({ limit: 2, cursor: page2.nextCursor! }); + + expect(page3.data.map((r) => r.id)).toEqual(["a"]); + expect(page3.nextCursor).toBeNull(); + + // Verify no row appears on more than one page. + const seen = new Set([ + ...page1.data.map((r) => r.id), + ...page2.data.map((r) => r.id), + ...page3.data.map((r) => r.id), + ]); + expect(seen.size).toBe(5); + }); + + it("handles mixed-timestamp rows: cursor crosses a timestamp boundary correctly", async () => { + const tsNewer = new Date("2026-07-28T12:00:01.000Z"); + const tsOlder = new Date("2026-07-28T12:00:00.000Z"); + + // Page 1: two newer rows; cursor points at (tsNewer, "id-b"). + const page1Rows = [ + makeRow("id-c", tsNewer), + makeRow("id-b", tsNewer), + makeRow("id-a", tsOlder), // look-ahead + ]; + mockDb.limit.mockResolvedValueOnce(page1Rows); + + const page1 = await getAuditLogs({ limit: 2 }); + expect(page1.data.map((r) => r.id)).toEqual(["id-c", "id-b"]); + + // Page 2: next page starts at an older timestamp → predicate branch: + // (created_at < tsNewer) ← the simpler branch, not the tie-breaker. + const page2Rows = [makeRow("id-a", tsOlder)]; + mockDb.limit.mockResolvedValueOnce(page2Rows); + + const page2 = await getAuditLogs({ limit: 2, cursor: page1.nextCursor! }); + expect(page2.data.map((r) => r.id)).toEqual(["id-a"]); + expect(page2.nextCursor).toBeNull(); + }); + }); + + describe("edge cases", () => { + it("returns empty page with null cursor when DB returns no rows", async () => { + mockDb.limit.mockResolvedValue([]); + + const result = await getAuditLogs({ limit: 10 }); + + expect(result.data).toHaveLength(0); + expect(result.nextCursor).toBeNull(); + }); + + it("treats an invalid cursor as no cursor (first-page behaviour)", async () => { + mockDb.limit.mockResolvedValue([]); + + const result = await getAuditLogs({ limit: 5, cursor: "not-a-valid-cursor!!" }); + + // Invalid cursor → no keyset predicate → WHERE arg is undefined. + const whereArg = mockDb.where.mock.calls[0][0]; + expect(whereArg).toBeUndefined(); + expect(result.data).toHaveLength(0); + }); + + it("clamps limit to DEFAULT_PAGE_SIZE (20) when limit is omitted", async () => { + mockDb.limit.mockResolvedValue([]); + + await getAuditLogs({}); + + // DB receives DEFAULT_PAGE_SIZE + 1 (look-ahead). + expect(mockDb.limit).toHaveBeenCalledWith(21); + }); + + it("applies action and actor filters together with the cursor predicate", async () => { + const ts = new Date("2026-07-28T10:00:00.000Z"); + const rows = [makeRow("id-1", ts), makeRow("id-2", ts)]; + mockDb.limit.mockResolvedValue(rows); + + const cursor = encodeCursor({ sortValue: ts.toISOString(), id: "id-5" }); + + await getAuditLogs({ + action: "market.create", + actor: "GADDR1", + cursor, + limit: 1, + }); + + // WHERE clause must be defined (action + actor + cursor predicate combined). + const whereArg = mockDb.where.mock.calls[0][0]; + expect(whereArg).toBeDefined(); + }); + }); +});