- wau/mau trailing scans run hourly and on day finalization, not every tick - exclusion lookup failures cached 30s so an st outage cannot amplify - unverified relation filter dropped; player emptiness checked in js - anonymous unauthenticated read failures no longer logged - alerts and exclusions ensure supertokens init on cold pods
408 lines
12 KiB
TypeScript
408 lines
12 KiB
TypeScript
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() {}
|
|
},
|
|
}));
|
|
|
|
vi.mock("@/lib/telemetry/exclusions.server", () => ({
|
|
isExcludedPlayerId: async (playerId?: string) => playerId === "excluded-player",
|
|
isExcludedPhone: () => false,
|
|
}));
|
|
|
|
import { recordDeniedServerFn, serverFnLoggingMiddleware } from "./activities";
|
|
import { setRequestActor } from "@/lib/telemetry/request-context.server";
|
|
import { redirect } from "@tanstack/react-router";
|
|
|
|
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);
|
|
});
|
|
});
|
|
|
|
const flushWrites = () => new Promise((resolve) => setTimeout(resolve, 20));
|
|
|
|
describe("serverFnLoggingMiddleware read handling", () => {
|
|
it("skips successful read fns", async () => {
|
|
setRequest("http://localhost:3000/_serverFn/x");
|
|
|
|
await runMiddleware({
|
|
next: async () => successEnvelope,
|
|
data: undefined,
|
|
context: {},
|
|
serverFnMeta: { id: "x", name: "getPlayerStats" },
|
|
});
|
|
|
|
await flushWrites();
|
|
expect(h.createActivity).not.toHaveBeenCalled();
|
|
});
|
|
|
|
it("records failed read fns", async () => {
|
|
setRequest("http://localhost:3000/_serverFn/x");
|
|
|
|
await runMiddleware({
|
|
next: async () => ({
|
|
result: { success: false, error: { code: "NOT_FOUND" } },
|
|
}),
|
|
data: undefined,
|
|
context: {},
|
|
serverFnMeta: { id: "x", name: "getPlayerStats" },
|
|
});
|
|
|
|
await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1));
|
|
expect(h.createActivity.mock.calls[0][0]).toMatchObject({
|
|
name: "getPlayerStats",
|
|
success: false,
|
|
});
|
|
});
|
|
|
|
it("records thrown errors from read fns", async () => {
|
|
setRequest("http://localhost:3000/_serverFn/x");
|
|
|
|
await expect(
|
|
runMiddleware({
|
|
next: async () => {
|
|
throw new Error("db down");
|
|
},
|
|
data: undefined,
|
|
context: {},
|
|
serverFnMeta: { id: "x", name: "listPlayers" },
|
|
})
|
|
).rejects.toThrow("db down");
|
|
|
|
await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1));
|
|
});
|
|
});
|
|
|
|
describe("serverFnLoggingMiddleware control flow and dedup", () => {
|
|
it("does not record a thrown Response (session refresh)", async () => {
|
|
setRequest("http://localhost:3000/_serverFn/doThing");
|
|
|
|
await expect(
|
|
runMiddleware({
|
|
next: async () => {
|
|
throw new Response("{}", { status: 401 });
|
|
},
|
|
data: undefined,
|
|
context: {},
|
|
})
|
|
).rejects.toBeInstanceOf(Response);
|
|
|
|
await flushWrites();
|
|
expect(h.createActivity).not.toHaveBeenCalled();
|
|
});
|
|
|
|
it("does not record thrown redirects", async () => {
|
|
setRequest("http://localhost:3000/_serverFn/doThing");
|
|
|
|
await expect(
|
|
runMiddleware({
|
|
next: async () => {
|
|
throw redirect({ to: "/" });
|
|
},
|
|
data: undefined,
|
|
context: {},
|
|
})
|
|
).rejects.toBeDefined();
|
|
|
|
await flushWrites();
|
|
expect(h.createActivity).not.toHaveBeenCalled();
|
|
});
|
|
|
|
it("does not double-record when a denial was already recorded for the request", async () => {
|
|
setRequest("http://localhost:3000/_serverFn/doThing");
|
|
recordDeniedServerFn(h.request as unknown as Request, { player_id: "p1" }, { name: "doThing" });
|
|
|
|
await expect(
|
|
runMiddleware({
|
|
next: async () => {
|
|
throw new Error("Unauthorized");
|
|
},
|
|
data: undefined,
|
|
context: {},
|
|
serverFnMeta: { id: "x", name: "doThing" },
|
|
})
|
|
).rejects.toThrow("Unauthorized");
|
|
|
|
await flushWrites();
|
|
expect(h.createActivity).toHaveBeenCalledTimes(1);
|
|
expect(h.createActivity.mock.calls[0][0].error).toContain("FORBIDDEN");
|
|
});
|
|
|
|
it("does not record anonymous Unauthenticated failures", async () => {
|
|
setRequest("http://localhost:3000/_serverFn/x");
|
|
|
|
await expect(
|
|
runMiddleware({
|
|
next: async () => {
|
|
throw new Error("Unauthenticated");
|
|
},
|
|
data: undefined,
|
|
context: {},
|
|
serverFnMeta: { id: "x", name: "fetchMe" },
|
|
})
|
|
).rejects.toThrow("Unauthenticated");
|
|
|
|
await flushWrites();
|
|
expect(h.createActivity).not.toHaveBeenCalled();
|
|
});
|
|
|
|
it("still records Unauthenticated failures for identified actors", async () => {
|
|
setRequest("http://localhost:3000/_serverFn/x");
|
|
setRequestActor(h.request as unknown as Request, { playerId: "p1" });
|
|
|
|
await expect(
|
|
runMiddleware({
|
|
next: async () => {
|
|
throw new Error("Unauthenticated");
|
|
},
|
|
data: undefined,
|
|
context: {},
|
|
serverFnMeta: { id: "x", name: "fetchMe" },
|
|
})
|
|
).rejects.toThrow("Unauthenticated");
|
|
|
|
await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1));
|
|
});
|
|
|
|
it("does not record activity for excluded players", async () => {
|
|
setRequest("http://localhost:3000/_serverFn/doThing");
|
|
setRequestActor(h.request as unknown as Request, { playerId: "excluded-player" });
|
|
|
|
await runMiddleware({
|
|
next: async () => successEnvelope,
|
|
data: undefined,
|
|
context: {},
|
|
});
|
|
|
|
await flushWrites();
|
|
expect(h.createActivity).not.toHaveBeenCalled();
|
|
});
|
|
|
|
it("prefers the stashed request actor over middleware context", async () => {
|
|
setRequest("http://localhost:3000/_serverFn/doThing");
|
|
setRequestActor(h.request as unknown as Request, { playerId: "p9" });
|
|
|
|
await runMiddleware({
|
|
next: async () => successEnvelope,
|
|
data: undefined,
|
|
context: { metadata: { player_id: "p1" } },
|
|
});
|
|
|
|
await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1));
|
|
expect(h.createActivity.mock.calls[0][0].player).toBe("p9");
|
|
});
|
|
});
|
|
|
|
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,
|
|
});
|
|
});
|
|
});
|