diff --git a/CHANGELOG.md b/CHANGELOG.md index a1edb6a53..094b013c7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,15 @@ Newest first. `Unreleased` is what is on `main` and not yet tagged. ## Unreleased +### Paging the audit trail no longer skips rows written in the same millisecond + +`GET /api/admin/audit-events` hands out a `nextCursor` built from the last row's timestamp, which the +server read at millisecond precision while PostgreSQL keeps microseconds. The cursor therefore named a +moment just before that row, and the rows the next page should have started with, written earlier in +the same millisecond, were on no page at all. Anything that walked the trail page by page could miss +them without any sign of it. The cursor now carries the row's full timestamp. A cursor issued before +this change still reads. + ### The New chat shortcut works on a Russian or Greek keyboard layout Settings lists New chat as Shift+N, and the app matched the character the keystroke wrote. A layout diff --git a/server/src/audit.ts b/server/src/audit.ts index fe921dc9f..9df95edb5 100644 --- a/server/src/audit.ts +++ b/server/src/audit.ts @@ -1,4 +1,14 @@ -import { and, desc, eq, gt, inArray, lt, or, sql } from "drizzle-orm"; +import { + and, + desc, + eq, + getTableColumns, + gt, + inArray, + lt, + or, + sql, +} from "drizzle-orm"; import type { PgColumn } from "drizzle-orm/pg-core"; import type { Database } from "./db/client"; import { auditEvents } from "./db/schema"; @@ -717,11 +727,14 @@ export function createAuditReader(database: Database): AuditReader { const cursor = query.cursor ? decodeCursor(query.cursor) : undefined; if (cursor) { + // Bound as text and cast by PostgreSQL, not as a `Date`, which would drop the microseconds + // the cursor below carries. + const createdAt = sql`${cursor.createdAt}::timestamptz`; conditions.push( or( - lt(auditEvents.createdAt, new Date(cursor.createdAt)), + lt(auditEvents.createdAt, createdAt), and( - eq(auditEvents.createdAt, new Date(cursor.createdAt)), + eq(auditEvents.createdAt, createdAt), lt(auditEvents.id, cursor.id), ), ), @@ -729,7 +742,18 @@ export function createAuditReader(database: Database): AuditReader { } const rows = await database - .select() + .select({ + ...getTableColumns(auditEvents), + /* + * The row's own timestamp to the microsecond, for the cursor only. + * + * `created_at` keeps microseconds and a `Date` keeps milliseconds, so a cursor made from + * `createdAt` named a moment just before the row it came from. The rows the next page + * should have started with, written earlier in that same millisecond or at the same + * instant, then compared as newer than the cursor and were on no page at all. + */ + cursorCreatedAt: sql`to_char(${auditEvents.createdAt} at time zone 'UTC', 'YYYY-MM-DD"T"HH24:MI:SS.US"Z"')`, + }) .from(auditEvents) .where(and(...conditions)) .orderBy(desc(auditEvents.createdAt), desc(auditEvents.id)) @@ -739,7 +763,7 @@ export function createAuditReader(database: Database): AuditReader { const last = page.at(-1); return { - events: page.map((event) => ({ + events: page.map(({ cursorCreatedAt: _cursorOnly, ...event }) => ({ ...event, createdAt: event.createdAt.toISOString(), payload: event.payload as Record, @@ -748,7 +772,7 @@ export function createAuditReader(database: Database): AuditReader { hasNextPage && last ? encodeCursor({ id: last.id, - createdAt: last.createdAt.toISOString(), + createdAt: last.cursorCreatedAt, }) : undefined, }; diff --git a/server/tests/audit-cursor.integration.test.ts b/server/tests/audit-cursor.integration.test.ts index b238a35f2..6c9132480 100644 --- a/server/tests/audit-cursor.integration.test.ts +++ b/server/tests/audit-cursor.integration.test.ts @@ -1,8 +1,10 @@ import { describe, expect, test } from "bun:test"; +import { sql } from "drizzle-orm"; import { createApp } from "../src/app"; import { createAuditReader } from "../src/audit"; import { loadConfig } from "../src/config"; import { createDatabase } from "../src/db/client"; +import { auditEvents } from "../src/db/schema"; import { TEST_POOL, testDatabaseUrl } from "./support/database"; import { testEnvironment } from "./support/environment"; @@ -93,3 +95,66 @@ describe("a cursor the trail's own columns have to parse", () => { expect(await response.json()).toHaveProperty("events"); }); }); + +/** + * Walking the trail with the cursor the endpoint itself hands out. + * + * `created_at` keeps microseconds and a JavaScript `Date` keeps milliseconds, so a cursor built from + * the row as the driver returns it names a moment slightly before the row it was taken from. Rows + * written in the same millisecond as the last one on a page then compare as newer than the cursor + * and never come back on any page. + */ +describe("a cursor over rows written within one millisecond", () => { + const reader = createAuditReader(database); + + /** Rows in one statement, so they share `now()`, at the given microsecond offsets into its millisecond. */ + async function rowsAt(targetId: string, micros: number[]) { + return database + .insert(auditEvents) + .values( + micros.map((offset) => ({ + eventType: "configuration.changed", + targetType: "audit_cursor_test", + targetId, + payload: {}, + createdAt: sql`date_trunc('milliseconds', now()) + ${offset}::int * interval '1 microsecond'`, + })), + ) + .returning({ id: auditEvents.id }); + } + + async function walk(targetId: string) { + const seen: string[] = []; + let cursor: string | undefined; + for (let page = 0; page < 10; page += 1) { + const result = await reader.list({ + targetId, + limit: 1, + ...(cursor ? { cursor } : {}), + }); + seen.push(...result.events.map((event) => event.id)); + if (!result.nextCursor) break; + cursor = result.nextCursor; + } + return seen; + } + + test("reaches every row, newest first, when they are microseconds apart", async () => { + const targetId = `cursor-precision-${crypto.randomUUID()}`; + const [newest, middle, oldest] = await rowsAt(targetId, [789, 456, 123]); + + expect(await walk(targetId)).toEqual([newest?.id, middle?.id, oldest?.id]); + }); + + test("reaches every row when they share one instant", async () => { + const targetId = `cursor-precision-${crypto.randomUUID()}`; + const rows = await rowsAt(targetId, [456, 456, 456]); + // One instant, so the id alone orders them, descending as the reader does. + const expected = rows + .map((row) => row.id) + .sort() + .reverse(); + + expect(await walk(targetId)).toEqual(expected); + }); +});