From e46948cce0e2adeb14caaffae9d6f687b83177ba Mon Sep 17 00:00:00 2001 From: kevin9327 <5299031+kevin9327@users.noreply.github.com> Date: Thu, 17 Sep 2026 06:31:46 +0900 Subject: [PATCH] Page the audit trail from the row's own microsecond, so rows in the same millisecond are not skipped created_at keeps microseconds and a JavaScript Date keeps milliseconds, so the cursor built from a row named a moment just before that row. The rows the next page should start with, written earlier in the same millisecond or at the same instant, then compared as newer than the cursor and were on no page at all. Co-Authored-By: Claude Opus 5 --- CHANGELOG.md | 9 +++ server/src/audit.ts | 36 ++++++++-- server/tests/audit-cursor.integration.test.ts | 65 +++++++++++++++++++ 3 files changed, 104 insertions(+), 6 deletions(-) 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); + }); +});