feat(diagnostics): correlate staff operations errors and audit records
CI / check (push) Successful in 56s
CI / deploy (push) Successful in 19s
CI / publish-container (push) Successful in 1m15s

This commit is contained in:
Simo committed 2026-09-11 00:34:49 +02:00
1 parent 440ce4e556
commit a2954e4408
14 files changed
+379 -16

No files matched your search

+11 -6
View File
@@ -167,8 +167,8 @@ export default async function CmsErrorsPage({
<details key={fingerprint} className="admin-card overflow-hidden">
<summary className="cursor-pointer">
<span className="text-xs text-muted-foreground">
{t(r.resolved ? "resolved" : "open")} · {r.source} ·{" "}
{t("occurrences", { count: events.length })} · {r.at}
{t(r.resolved ? "resolved" : "open")} · {r.source} ·{" "}
{t("occurrences", { count: events.length })} · {r.at}
</span>
<p className="font-semibold break-words">{r.event}</p>
<p className="text-sm break-words">{r.message}</p>
@@ -248,6 +248,11 @@ export default async function CmsErrorsPage({
)}
</form>
)}
{metrics.auditLink && (
<Link href={metrics.auditLink} className="btn btn-outline">
{t("auditTrail")}
</Link>
)}
{metrics.operationLink && (
<Link
href={metrics.operationLink}
@@ -263,9 +268,9 @@ export default async function CmsErrorsPage({
<ul className="mt-2 space-y-2">
{metrics.releases.map((release) => (
<li key={release.release} className="break-all">
<code>{release.release}</code> ·{" "}
{t("occurrences", { count: release.count })} ·{" "}
{release.firstAt} — {release.lastAt}
<code>{release.release}</code> ·{" "}
{t("occurrences", { count: release.count })} ·{" "}
{release.firstAt} — {release.lastAt}
</li>
))}
</ul>
@@ -308,7 +313,7 @@ export default async function CmsErrorsPage({
<ul>
{events.map((e) => (
<li key={e.id} className="break-all">
{e.at} · {e.id}
{e.at} · {e.id}
</li>
))}
</ul>
+10
View File
@@ -1,5 +1,6 @@
"use client";
import Link from "next/link";
import { useSearchParams } from "next/navigation";
import { useTranslations } from "next-intl";
import { DataTable } from "@/components/admin/data-table";
@@ -10,6 +11,7 @@ import type { DataTableColumn, PaginatedResult } from "@/types/common";
import { AuditFilters } from "./audit-filters";
interface AuditRow {
operationId?: string | null;
id: number;
username: string;
action: string;
@@ -106,6 +108,14 @@ export function AuditTable({ data }: AuditTableProps) {
render: (_value, row) => (
<div className="space-y-2">
<DiffCell row={row} />
{row.operationId && (
<Link
className="text-xs underline break-all"
href={`/admin/devops/cms-errors?q=${encodeURIComponent(row.operationId)}`}
>
{t("audit.operation")}: {row.operationId}
</Link>
)}
{["history_update", "history_restore"].includes(row.action) && (
<HistoryRestore id={row.id} />
)}
+5 -2
View File
@@ -8,6 +8,7 @@ import {
WebsiteArticles,
} from "@/db/schema";
import type { db } from "@/lib/db";
import { getOperationContext } from "@/lib/foundation/request-context";
import { type HistorySnapshot, sameSnapshot } from "./model";
export type HistoryKind = "category" | "category_bc" | "prices" | "news";
export type HistoryTransaction = Parameters<
@@ -117,8 +118,10 @@ export async function recordHistory(
action,
target: kind,
targetId: Number(id) <= 2147483647 ? Number(id) : null,
details:
Number(id) > 2147483647 ? JSON.stringify({ targetId: String(id) }) : null,
details: JSON.stringify({
...getOperationContext(),
...(Number(id) > 2147483647 ? { targetId: String(id) } : {}),
}),
before: serializedBefore,
after: serializedAfter,
createdAt: new Date().toISOString(),
+135
View File
@@ -0,0 +1,135 @@
import { NextRequest, NextResponse } from "next/server";
import { beforeEach, describe, expect, it, vi } from "vitest";
import { getOperationContext } from "./foundation/request-context";
const state = vi.hoisted(() => ({
authorized: true,
permitted: true,
csrf: true,
}));
vi.mock("@/lib/admin/authorization-events", () => ({
logAuthorizationEvent: vi.fn(),
}));
vi.mock("@/lib/foundation/security", () => ({
validateCsrfToken: async () => state.csrf,
}));
vi.mock("@/lib/permissions", () => ({
getApiAdminContext: async () =>
state.authorized
? { session: { user: { id: 42, rank: 7 } }, permissions: [] }
: null,
canAccess: () => state.permitted,
}));
vi.mock("@/lib/server-log", () => ({
logServerError: () => "error-reference",
}));
vi.mock("@/lib/services/catalog-git-queue", () => ({
catalogExportEnabled: () => false,
isCatalogMutation: () => false,
beginCatalogExport: vi.fn(),
}));
import { withAdmin } from "./api-handler";
const request = () =>
new NextRequest("https://hotel.test/api/admin/example", {
headers: { "x-operation-id": "forged-client-id" },
});
describe("admin API correlation", () => {
beforeEach(() => {
state.authorized = true;
state.permitted = true;
state.csrf = true;
});
it("matches the response ID to asynchronous work without trusting a supplied ID", async () => {
const handler = withAdmin({ permission: "users.view" }, async () => {
await Promise.resolve();
return NextResponse.json(getOperationContext());
});
const [a, b] = await Promise.all([handler(request()), handler(request())]);
expect(a.headers.get("x-operation-id")).not.toBe("forged-client-id");
expect(a.headers.get("x-operation-id")).not.toBe(
b.headers.get("x-operation-id"),
);
expect(await a.json()).toEqual({
operationId: a.headers.get("x-operation-id"),
userId: 42,
});
expect(getOperationContext()).toEqual({});
});
it("preserves redirects and separate set-cookie values", async () => {
const handler = withAdmin({}, () => {
const response = NextResponse.redirect(
"https://hotel.test/admin/users",
307,
);
response.cookies.set("first", "one", { httpOnly: true });
response.cookies.set("second", "two", { httpOnly: true });
return response;
});
const response = await handler(request());
expect(response.status).toBe(307);
expect(response.headers.get("location")).toBe(
"https://hotel.test/admin/users",
);
expect(response.headers.getSetCookie()).toHaveLength(2);
expect(response.headers.getSetCookie()).toEqual(
expect.arrayContaining([
expect.stringContaining("first=one"),
expect.stringContaining("second=two"),
]),
);
expect(response.headers.get("x-operation-id")).toBeTruthy();
});
it("returns streaming headers before completion and preserves every chunk", async () => {
let controller: ReadableStreamDefaultController<Uint8Array> | undefined;
const handler = withAdmin(
{},
() =>
new Response(
new ReadableStream({
start(value) {
controller = value;
},
}),
{
headers: {
"content-type": "text/event-stream",
"x-custom": "retained",
},
},
),
);
const response = await handler(request());
expect(response.headers.get("content-type")).toBe("text/event-stream");
expect(response.headers.get("x-custom")).toBe("retained");
const body = response.text();
controller?.enqueue(new TextEncoder().encode("data: first\n\n"));
controller?.enqueue(new TextEncoder().encode("data: last\n\n"));
controller?.close();
expect(await body).toBe("data: first\n\ndata: last\n\n");
});
it("adds correlation to authentication, permission and handler failures", async () => {
const handler = withAdmin({ permission: "users.view" }, () => {
throw new Error("private-database-message");
});
state.authorized = false;
const unauthorized = await handler(request());
expect(unauthorized.status).toBe(401);
expect(unauthorized.headers.get("x-operation-id")).toBeTruthy();
state.authorized = true;
state.permitted = false;
const forbidden = await handler(request());
expect(forbidden.status).toBe(403);
expect(forbidden.headers.get("x-operation-id")).toBeTruthy();
state.permitted = true;
const failed = await handler(request());
expect(failed.status).toBe(500);
expect(failed.headers.get("x-operation-id")).toBeTruthy();
expect(await failed.json()).toEqual({
ok: false,
error: "Internal server error",
errorId: "error-reference",
});
});
});
+17
View File
@@ -1,6 +1,12 @@
import { after, type NextRequest, NextResponse } from "next/server";
import { logAuthorizationEvent } from "@/lib/admin/authorization-events";
import {
createStore,
runWithStore,
setContextUserId,
} from "@/lib/foundation/request-context";
import { validateCsrfToken } from "@/lib/foundation/security";
import type { IpAddress, UserId } from "@/lib/foundation/types";
import { canAccess, getApiAdminContext } from "@/lib/permissions";
import { logServerError } from "@/lib/server-log";
@@ -30,6 +36,8 @@ export function withAdmin(
handler: AdminHandler,
) {
return async (request: NextRequest, routeContext: RouteContext = {}) => {
const store = createStore("unknown" as IpAddress);
const response = await runWithStore(store, async () => {
// CSRF required for mutating admin APIs unless explicitly opted out.
const csrfRequired =
options.requireCsrf !== false && MUTATING_METHODS.has(request.method);
@@ -86,6 +94,7 @@ export function withAdmin(
{ status: 403 },
);
}
setContextUserId(Number(context.session.user.id) as UserId);
let finishExport: (() => Promise<void>) | undefined;
try {
if (
@@ -131,5 +140,13 @@ export function withAdmin(
{ status: 500 },
);
}
});
const headers = new Headers(response.headers);
headers.set("x-operation-id", store.requestId);
return new Response(response.body, {
status: response.status,
statusText: response.statusText,
headers,
});
};
}
+17
View File
@@ -58,3 +58,20 @@ it("creates only recognized local operation links", () => {
])
expect(errorOperationLink({ ...base, context: { path } })).toBeNull();
});
it("links server operation IDs to the audit search without trusting browser IDs", () => {
const record = createErrorRecord("server", "test", "failed", {
operationId: "op-123",
});
expect(summarizeErrorGroup([record]).auditLink).toBe(
"/admin/logs/audit?search=op-123",
);
expect(
summarizeErrorGroup([{ ...record, source: "browser" }]).auditLink,
).toBeNull();
expect(
summarizeErrorGroup([
{ ...record, context: { operationId: "../../secrets" } },
]).auditLink,
).toBeNull();
});
+6
View File
@@ -69,5 +69,11 @@ export function summarizeErrorGroup(events: CmsErrorRecord[]) {
releases: [...releases.values()],
latest,
operationLink: latest ? errorOperationLink(latest) : null,
auditLink:
latest?.source === "server" &&
typeof latest.context.operationId === "string" &&
/^[a-zA-Z0-9-]{1,100}$/.test(latest.context.operationId)
? `/admin/logs/audit?search=${encodeURIComponent(latest.context.operationId)}`
: null,
};
}
@@ -0,0 +1,27 @@
import { expect, it } from "vitest";
import {
createStore,
getOperationContext,
runWithStore,
setContextUserId,
} from "./request-context";
import type { IpAddress, UserId } from "./types";
it("isolates operation IDs and users across concurrent asynchronous requests", async () => {
const first = createStore("test" as IpAddress),
second = createStore("test" as IpAddress);
expect(first.requestId).not.toBe(second.requestId);
await Promise.all(
[first, second].map((store, index) =>
runWithStore(store, async () => {
setContextUserId((index + 1) as UserId);
await new Promise((resolve) => setTimeout(resolve, 5 - index));
expect(getOperationContext()).toEqual({
operationId: store.requestId,
userId: index + 1,
});
}),
),
);
expect(getOperationContext()).toEqual({});
});
+14
View File
@@ -38,3 +38,17 @@ export function setContextUserId(userId: UserId): void {
const store = als.getStore();
if (store) store.userId = userId;
}
/** Stable correlation data exists only inside an active request or job. */
export function getOperationContext(): {
operationId?: string;
userId?: number;
} {
const store = als.getStore();
return store
? {
operationId: store.requestId,
...(store.userId === null ? {} : { userId: Number(store.userId) }),
}
: {};
}
+49
View File
@@ -0,0 +1,49 @@
import { beforeEach, describe, expect, it, vi } from "vitest";
import {
createStore,
getOperationContext,
runWithStore,
setContextUserId,
} from "./foundation/request-context";
import type { IpAddress, UserId } from "./foundation/types";
const state = vi.hoisted(() => ({
records: [] as { context: Record<string, unknown> }[],
}));
vi.mock("./error-monitor", async (original) => {
const actual = await original<typeof import("./error-monitor")>();
return {
...actual,
captureCmsError: (...args: Parameters<typeof actual.createErrorRecord>) => {
const record = actual.createErrorRecord(...args);
state.records.push(record);
return record.id;
},
};
});
import { logger } from "./logger";
describe("logger correlation boundaries", () => {
beforeEach(() => {
state.records = [];
});
it("keeps trusted operation context when metadata is large or supplies conflicting IDs", () => {
const store = createStore("test" as IpAddress);
runWithStore(store, () => {
setContextUserId(42 as UserId);
logger.error("failed", {
...Object.fromEntries(
Array.from({ length: 30 }, (_, index) => [`field${index}`, index]),
),
operationId: "forged",
userId: 99,
});
});
expect(state.records[0].context).toMatchObject({
operationId: store.requestId,
userId: 42,
});
expect(getOperationContext()).toEqual({});
});
});
+10 -6
View File
@@ -1,6 +1,7 @@
import pino from "pino";
import { env } from "@/env";
import { captureCmsError } from "./error-monitor";
import { getOperationContext } from "./foundation/request-context";
type LogLevel = "debug" | "info" | "warn" | "error";
@@ -31,16 +32,16 @@ export function generateRequestId(): string {
return `${Date.now().toString(36)}-${requestIdCounter.toString(36)}`;
}
/** Compatibility wrapper — existing call sites use (message, meta). */
/** Compatibility wrapper — existing call sites use (message, meta). */
export const logger = {
debug(message: string, meta: Record<string, unknown> = {}): void {
pinoLogger.debug(meta, message);
pinoLogger.debug({ ...meta, ...getOperationContext() }, message);
},
info(message: string, meta: Record<string, unknown> = {}): void {
pinoLogger.info(meta, message);
pinoLogger.info({ ...meta, ...getOperationContext() }, message);
},
warn(message: string, meta: Record<string, unknown> = {}): void {
pinoLogger.warn(meta, message);
pinoLogger.warn({ ...meta, ...getOperationContext() }, message);
},
error(message: string, meta: Record<string, unknown> = {}): string {
const error =
@@ -55,8 +56,11 @@ export const logger = {
? meta.error
: message,
);
const errorId = captureCmsError("server", message, error, meta);
pinoLogger.error({ ...meta, errorId }, message);
const operation = getOperationContext();
// Keep trusted correlation first so bounded error context retains it.
const context = { ...operation, ...meta, ...operation };
const errorId = captureCmsError("server", message, error, context);
pinoLogger.error({ ...context, errorId }, message);
return errorId;
},
};
+3 -1
View File
@@ -36,8 +36,10 @@ describe("audit query filters", () => {
expect(query.sql).not.toContain("Alice");
expect(query.sql).toContain("`admin_audit_log`.`user_id` in (select");
expect(query.sql).toContain("`admin_audit_log`.`created_at` >= ?");
expect(query.sql).toContain("`admin_audit_log`.`details` like ?");
expect(query.sql).toContain("`admin_audit_log`.`created_at` < ?");
expect(query.params.slice(0, 6)).toEqual([
expect(query.params.slice(0, 7)).toEqual([
"%user%",
"%user%",
"%user%",
"update",
+59
View File
@@ -49,6 +49,12 @@ vi.mock("@/lib/db", () => ({
vi.mock("@/env", () => ({ env: {} }));
import {
createStore,
runWithStore,
setContextUserId,
} from "@/lib/foundation/request-context";
import type { IpAddress, UserId } from "@/lib/foundation/types";
import { getAuditLogs, logAudit } from "./audit";
beforeEach(() => {
@@ -56,6 +62,25 @@ beforeEach(() => {
});
describe("logAudit", () => {
it("stores the same trusted operation ID across asynchronous audit writes", async () => {
const store = createStore("test" as IpAddress);
await runWithStore(store, async () => {
setContextUserId(42 as UserId);
await Promise.resolve();
await logAudit({
userId: 42,
action: "update",
target: "user",
after: { name: "Alice" },
});
});
expect(JSON.parse(insertValues.mock.calls[0][0].details)).toEqual({
operationId: store.requestId,
userId: 42,
});
await logAudit({ userId: 42, action: "outside", target: "user" });
expect(JSON.parse(insertValues.mock.calls[1][0].details)).toEqual({});
});
it("creates an audit entry", async () => {
insertValues.mockResolvedValue({ id: 1 });
await logAudit({
@@ -189,6 +214,40 @@ describe("getAuditLogs", () => {
});
describe("audit response privacy", () => {
it("exposes only a validated operation ID, never arbitrary stored details", async () => {
selectRows.mockResolvedValue([
{
id: 1,
userId: 42,
diff: null,
before: null,
after: null,
operationDetails: JSON.stringify({
operationId: "op-123",
token: "private-token",
ip: "private-ip",
}),
},
{
id: 2,
userId: 42,
diff: null,
before: null,
after: null,
operationDetails: JSON.stringify({
operationId: "../../other?token=private",
}),
},
]);
selectCount.mockResolvedValue([{ value: 2 }]);
selectUsers.mockResolvedValue([]);
const result = await getAuditLogs();
expect(result.rows[0].operationId).toBe("op-123");
expect(result.rows[1].operationId).toBeNull();
expect(JSON.stringify(result.rows)).not.toContain("private-token");
expect(JSON.stringify(result.rows)).not.toContain("private-ip");
expect(result.rows[0]).not.toHaveProperty("operationDetails");
});
it("does not serialize legacy snapshot secrets to the client", async () => {
selectRows.mockResolvedValue([
{
+16 -1
View File
@@ -1,5 +1,6 @@
import { and, count, desc, eq, gte, inArray, like, lt, or } from "drizzle-orm";
import { AdminAuditLog, db, User } from "@/lib/db";
import { getOperationContext } from "@/lib/foundation/request-context";
import { readAuditChanges } from "./audit-diff";
import { type AuditFilters, normalizeAuditFilters } from "./audit-filters";
@@ -60,6 +61,7 @@ export async function logAudit(entry: AuditEntry): Promise<void> {
await db.insert(AdminAuditLog).values({
userId: entry.userId,
details: JSON.stringify(getOperationContext()),
action: entry.action,
target: entry.target,
targetId: entry.targetId,
@@ -79,6 +81,7 @@ export async function getAuditLogs(options: AuditFilters = {}) {
? or(
like(AdminAuditLog.action, `%${search}%`),
like(AdminAuditLog.target, `%${search}%`),
like(AdminAuditLog.details, `%${search}%`),
)
: undefined,
action ? eq(AdminAuditLog.action, action) : undefined,
@@ -105,6 +108,7 @@ export async function getAuditLogs(options: AuditFilters = {}) {
target: AdminAuditLog.target,
targetId: AdminAuditLog.targetId,
diff: AdminAuditLog.diff,
operationDetails: AdminAuditLog.details,
before: AdminAuditLog.before,
after: AdminAuditLog.after,
createdAt: AdminAuditLog.createdAt,
@@ -131,8 +135,19 @@ export async function getAuditLogs(options: AuditFilters = {}) {
const enrichedRows = rows.map((r) => {
const details = readAuditChanges(r.diff, r.before, r.after);
let operationId: string | null = null;
try {
const meta = JSON.parse(r.operationDetails ?? "{}");
if (
typeof meta.operationId === "string" &&
/^[a-zA-Z0-9-]{1,100}$/.test(meta.operationId)
)
operationId = meta.operationId;
} catch {}
const { operationDetails: _privateDetails, ...safeRow } = r;
return {
...r,
...safeRow,
operationId,
// Only sanitized changes may cross the server/client boundary.
before: null,
after: null,