fix(audit): readable names, single writer, denial rows, redacted args

The activity log recorded Start's hashed function id (a sha256 URL
segment) as the name; the middleware now reads compile-time
serverFnMeta.name with the path segment as fallback. toServerResult
resolves { success:false } instead of throwing, so the middleware logged
failures as successes while toServerResult wrote a duplicate row with its
own dead name parser — the middleware is now the single writer and reads
the envelope's success flag. Admin denials, which threw before the logging
middleware ran, get their own audit row. Arguments are redacted
(phone/otp/token keys) and truncated at 2KB. The admin activities search
binds its filter parameters (likePattern escaping) instead of
interpolating raw input. Adds vitest with node-env tests for the
middleware, redaction, and filter utils, and extends logging coverage to
mutating fns that lacked it.
This commit is contained in:
2026-08-23 18:27:53 -07:00
parent 60e91d1371
commit 9fc79dfc07
18 changed files with 691 additions and 67 deletions
+226
View File
@@ -0,0 +1,226 @@
import { beforeEach, describe, expect, it, vi } from "vitest";
const h = vi.hoisted(() => ({
request: undefined as { url: string; headers: Headers } | undefined,
createActivity: vi.fn(),
}));
vi.mock("@tanstack/react-start/server", () => ({
getRequest: () => h.request,
}));
vi.mock("@/lib/pocketbase/client", () => ({
pbAdmin: { authPromise: Promise.resolve(), createActivity: h.createActivity },
}));
vi.mock("@/lib/logger", () => ({
Logger: class {
error() {}
info() {}
},
}));
import { recordDeniedServerFn, serverFnLoggingMiddleware } from "./activities";
type ServerHandler = (opts: {
next: () => Promise<unknown>;
data: unknown;
context: unknown;
serverFnMeta?: { id: string; name?: string; filename?: string };
}) => Promise<unknown>;
const runMiddleware = (opts: Parameters<ServerHandler>[0]) =>
(serverFnLoggingMiddleware as any).options.server(opts) as ReturnType<ServerHandler>;
const setRequest = (url: string, userAgent = "vitest") => {
h.request = { url, headers: new Headers({ "user-agent": userAgent }) };
};
const successEnvelope = { result: { success: true, data: {} } };
beforeEach(() => {
h.createActivity.mockReset();
});
describe("serverFnLoggingMiddleware", () => {
it("records the source name from the compile-time meta, not the hashed url segment", async () => {
const hashedId = "a".repeat(64);
setRequest(`http://localhost:3000/_serverFn/${hashedId}`);
await runMiddleware({
next: async () => successEnvelope,
data: undefined,
context: { metadata: { player_id: "p1" } },
serverFnMeta: {
id: hashedId,
name: "updatePlayer",
filename: "src/features/players/server.ts",
},
});
await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1));
expect(h.createActivity.mock.calls[0][0]).toMatchObject({
name: "updatePlayer",
player: "p1",
success: true,
user_agent: "vitest",
});
});
it("falls back to the last path segment when the meta carries no name", async () => {
setRequest("http://localhost:3000/_serverFn/deadbeef");
await runMiddleware({
next: async () => successEnvelope,
data: undefined,
context: {},
serverFnMeta: { id: "deadbeef" },
});
await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1));
expect(h.createActivity.mock.calls[0][0].name).toBe("deadbeef");
});
it("falls back to the last path segment when there is no meta at all", async () => {
setRequest("http://localhost:3000/_serverFn/legacySegment");
await runMiddleware({
next: async () => successEnvelope,
data: undefined,
context: {},
});
await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1));
expect(h.createActivity.mock.calls[0][0].name).toBe("legacySegment");
});
it("records no player when the session has no player_id", async () => {
setRequest("http://localhost:3000/_serverFn/doThing");
await runMiddleware({
next: async () => successEnvelope,
data: undefined,
context: {},
});
await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1));
expect(h.createActivity.mock.calls[0][0].player).toBeUndefined();
});
it("falls back to 'unknown' when the path has no trailing segment", async () => {
setRequest("http://localhost:3000/");
await runMiddleware({
next: async () => successEnvelope,
data: undefined,
context: {},
});
await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1));
expect(h.createActivity.mock.calls[0][0].name).toBe("unknown");
});
it("records success:false by reading the returned envelope, not by throwing", async () => {
setRequest("http://localhost:3000/_serverFn/doThing");
await runMiddleware({
next: async () => ({
result: {
success: false,
error: { code: "NOT_FOUND", userMessage: "nope" },
},
}),
data: undefined,
context: {},
});
await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1));
const row = h.createActivity.mock.calls[0][0];
expect(row.success).toBe(false);
expect(row.error).toContain("NOT_FOUND");
});
it("records success:false and rethrows when the handler throws", async () => {
setRequest("http://localhost:3000/_serverFn/doThing");
await expect(
runMiddleware({
next: async () => {
throw new Error("boom");
},
data: undefined,
context: {},
})
).rejects.toThrow("boom");
await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1));
expect(h.createActivity.mock.calls[0][0]).toMatchObject({
success: false,
error: "boom",
});
});
it("redacts sensitive argument keys before they reach the audit row", async () => {
setRequest("http://localhost:3000/_serverFn/login");
await runMiddleware({
next: async () => successEnvelope,
data: { phone: "+17135550142", first_name: "Ada" },
context: {},
});
await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1));
expect(h.createActivity.mock.calls[0][0].arguments).toEqual({
phone: "[redacted]",
first_name: "Ada",
});
});
it("truncates oversized arguments", async () => {
setRequest("http://localhost:3000/_serverFn/doThing");
await runMiddleware({
next: async () => successEnvelope,
data: { blob: "x".repeat(5000) },
context: {},
});
await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1));
const args = h.createActivity.mock.calls[0][0].arguments;
expect(args.truncated).toBeDefined();
expect(args.truncated.length).toBeLessThanOrEqual(2048);
});
});
describe("recordDeniedServerFn", () => {
const deniedRequest = (url: string) =>
({ url, headers: new Headers({ "user-agent": "vitest" }) }) as Request;
it("names the denial row from the meta so it matches the success rows", async () => {
recordDeniedServerFn(
deniedRequest(`http://localhost:3000/_serverFn/${"b".repeat(64)}`),
{ player_id: "p1" },
{ name: "createTournament" }
);
await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1));
expect(h.createActivity.mock.calls[0][0]).toMatchObject({
name: "createTournament",
player: "p1",
success: false,
error: "FORBIDDEN: Access denied",
});
});
it("still records a name when the meta is absent", async () => {
recordDeniedServerFn(
deniedRequest("http://localhost:3000/_serverFn/rawSegment")
);
await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1));
expect(h.createActivity.mock.calls[0][0]).toMatchObject({
name: "rawSegment",
success: false,
});
});
});