From d45b877e4618ee56a8423fbc3b24400d92d27303 Mon Sep 17 00:00:00 2001 From: mnoah1 Date: Mon, 12 Oct 2026 18:41:25 +0000 Subject: [PATCH] refactor(web): let hosts handle request logging Send web logs through per-request callbacks so hosts can use their own logging context. Keep Pino in the reference hosts, preserve original errors and structured fields, and isolate callback failures from page results. Builds on the web E2E layer in #838. --- AGENTS.md | 2 +- doc/rfc/web-ui.md | 2 +- web/platform/logging.test.ts | 27 +++++++ web/platform/logging.ts | 23 ++++++ web/platform/package.json | 6 +- web/pnpm-lock.yaml | 6 -- web/service/shared/health.test.ts | 27 ++++--- web/service/shared/health.ts | 7 +- web/service/shared/logging.test.ts | 32 +++++++++ web/service/shared/logging.ts | 9 +++ web/service/shared/package.json | 4 ++ .../stovepipe/src/app/healthz/route.ts | 4 +- web/service/stovepipe/src/next/page.tsx | 3 +- web/service/stovepipe/src/server/host.ts | 5 +- .../src/app/(protected)/[[...path]]/page.tsx | 7 +- .../submitqueue/src/app/healthz/route.ts | 4 +- web/service/submitqueue/src/next/page.tsx | 4 +- web/service/submitqueue/src/server/host.ts | 3 +- .../submitqueue/src/server/observability.ts | 5 ++ web/stovepipe/BUILD.bazel | 1 - web/stovepipe/README.md | 2 + web/stovepipe/controller/page.ts | 6 +- web/stovepipe/module.test.ts | 70 +++++++++++++++++++ web/stovepipe/module.ts | 23 ++++-- web/stovepipe/package.json | 2 - web/submitqueue/BUILD.bazel | 1 - web/submitqueue/README.md | 4 +- web/submitqueue/controller/controller.test.ts | 51 +++++++------- web/submitqueue/controller/gateway-call.ts | 8 +-- web/submitqueue/core/observability.test.ts | 8 +-- web/submitqueue/core/observability.ts | 4 -- web/submitqueue/module.test.ts | 63 +++++++++++------ web/submitqueue/module.ts | 27 ++++--- web/submitqueue/package.json | 2 - web/test/package/BUILD.bazel | 2 - web/test/package/consumer.ts | 5 +- web/test/package/pack_contents_test.py | 4 +- web/test/package/react18/BUILD.bazel | 1 - web/tool/library.bzl | 1 - 39 files changed, 336 insertions(+), 129 deletions(-) create mode 100644 web/platform/logging.test.ts create mode 100644 web/platform/logging.ts create mode 100644 web/service/shared/logging.test.ts create mode 100644 web/service/shared/logging.ts diff --git a/AGENTS.md b/AGENTS.md index 3da97424a..e85d949cb 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -194,7 +194,7 @@ Reviews send changes back for these more often than for anything else. Get them - **Build only for consumers in scope.** Do not add a package, interface, adapter, option, or second supported path for a consumer the change does not ship, such as a second host, a framework that "can't" import CSS, or a caller nobody has asked for. Extract shared code when the second real consumer arrives. When two ways of doing something would both be supported, pick one and enforce it. - **Every file, dependency, and call has a job you can name.** Skip work the behavior does not need: an upfront validation pass when each item is validated before use, an RPC whose result does not reach the output, a config file that restates defaults. If nothing breaks when you delete it, delete it. -- **Use ecosystem types directly.** Library code takes `*zap.SugaredLogger` and tally in Go, and a pino `Logger` and OpenTelemetry meter and tracer in web code, with a silent or no-op default. Do not define a homegrown `Logger` interface. Wrap a dependency only where the repository actually swaps implementations, which is what an extension contract is for. +- **Use ecosystem types directly.** Library code takes `*zap.SugaredLogger` and tally in Go, and OpenTelemetry meter and tracer in web code, with no-op defaults. Web libraries emit logs through a synchronous, request-scoped callback; the host chooses the logger and its request context. Pino belongs in the reference hosts. Do not define a homegrown `Logger` interface. Wrap a dependency only where the repository actually swaps implementations, which is what an extension contract is for. - **The library owns behavior; the host owns integration.** `platform/` and domain library code are framework-neutral and ship the complete behavior. In web code that includes layout, styling, pages, and API calls. A host supplies the server, auth, logging, metrics, transport, and configuration, and stays thin. Framework adapters (Next.js and the like) live in the host that uses them. Library code depends on the structural shape of a client, not on generated bindings or a transport. Only the host chooses implementations. - **Enforce boundaries; do not just document them.** Use Bazel `visibility` and tests that fail on forbidden imports. Generated bindings shared by in-repo consumers (such as a host and its e2e test) stay with the contract and are private to those consumers. Consumers outside the repository generate their own from the `.proto` sources. - **Mirror the repository layout in every language.** Go code uses the root tree. A workspace for another language repeats that layout inside itself: `web/platform`, `web/service`, `web/test/e2e`, and `web/tool`, not the repo-level `test/` or `tool/`. Do not substitute a framework's default layout (`web/e2e`), and do not call one host's wiring `platform`. diff --git a/doc/rfc/web-ui.md b/doc/rfc/web-ui.md index 298174829..49b7dead9 100644 --- a/doc/rfc/web-ui.md +++ b/doc/rfc/web-ui.md @@ -72,7 +72,7 @@ Summary is the default request view, and `?view=history` makes History shareable ## Observability and identity -Logging, metrics, and tracing are injected the way the Go services take zap and tally. The module accepts a pino logger, an OpenTelemetry meter, and an OpenTelemetry tracer, and default to a silent logger and the OpenTelemetry API's no-op providers. Every gateway read is timed and traced, and a failure is logged once under pino's `err` key with the request ID. The module times page loads too. The reference host logs with pino and exposes Prometheus metrics, from startup, only when a port is configured. It registers no tracer provider, so its spans are no-ops; a host that registers OpenTelemetry tracing can also add a gateway interceptor that propagates trace context. A host with another metrics client adapts it to the meter interface; if such adapters prove large, a smaller tally-shaped interface may replace it. +Metrics and tracing use injected OpenTelemetry meters and tracers, defaulting to the API's no-op providers. Logging uses a synchronous `onLog` callback passed with each page request: severity, message, and structured metadata, including the request ID and the original error under `error`. The host binds the callback to its request-scoped logger; the libraries have no logging-library dependency. Omitting the callback is silent, and callback exceptions cannot change page outcomes. Every gateway read and page load is timed and traced. The reference hosts write Pino JSON logs, serializing errors under `err`, and SubmitQueue exposes Prometheus metrics only when a port is configured. The reference host registers no tracer provider, so its spans are no-ops; a host that registers OpenTelemetry tracing can also add a gateway interceptor that propagates trace context. Identity has no shared library to depend on, so the host authenticates and passes an opaque principal. The module never sees credentials. diff --git a/web/platform/logging.test.ts b/web/platform/logging.test.ts new file mode 100644 index 000000000..adf14a446 --- /dev/null +++ b/web/platform/logging.test.ts @@ -0,0 +1,27 @@ +import { describe, expect, it, vi } from "vitest"; +import { createLogCallback } from "./logging.js"; + +describe("log delivery", () => { + it("preserves errors and request context without mutating caller metadata", () => { + const error = new Error("upstream detail"); + const metadata = Object.freeze({ error, queue: "repo/main", requestId: "other" }); + const onLog = vi.fn(); + const log = createLogCallback(onLog, { requestId: "request-1" }); + + log("warn", "Backend call failed", metadata); + + expect(onLog).toHaveBeenCalledWith("warn", "Backend call failed", { + error, + queue: "repo/main", + requestId: "request-1", + }); + expect(metadata.requestId).toBe("other"); + }); + + it("isolates a failing logging sink", () => { + const log = createLogCallback(() => { + throw new Error("logging unavailable"); + }); + expect(() => log("error", "Backend call failed", {})).not.toThrow(); + }); +}); diff --git a/web/platform/logging.ts b/web/platform/logging.ts new file mode 100644 index 000000000..23150d1b7 --- /dev/null +++ b/web/platform/logging.ts @@ -0,0 +1,23 @@ +export type LogLevel = "info" | "warn" | "error"; +export type LogMetadata = Readonly>; + +/** Synchronous host callback; metadata may contain an unmodified Error under `error`. */ +export type LogCallback = ( + level: LogLevel, + message: string, + metadata: LogMetadata, +) => void; + +/** Absent callbacks are silent; callback failures cannot change application outcomes. */ +export function createLogCallback( + onLog?: LogCallback, + context: LogMetadata = {}, +): LogCallback { + return (level, message, metadata) => { + try { + onLog?.(level, message, { ...metadata, ...context }); + } catch { + // Log delivery must not turn an upstream failure into a page failure. + } + }; +} diff --git a/web/platform/package.json b/web/platform/package.json index c8f2fa30b..0761d3fa1 100644 --- a/web/platform/package.json +++ b/web/platform/package.json @@ -19,7 +19,11 @@ "types": "./dist/path-segment.d.ts", "import": "./dist/path-segment.js" }, - "./styles.css": "./styles.css" + "./styles.css": "./styles.css", + "./logging": { + "types": "./dist/logging.d.ts", + "import": "./dist/logging.js" + } }, "scripts": { "build": "node -e \"require('node:fs').rmSync('dist',{recursive:true,force:true})\" && tsc -p tsconfig.build.json", diff --git a/web/pnpm-lock.yaml b/web/pnpm-lock.yaml index 0af1e54cb..0c3f8f0a6 100644 --- a/web/pnpm-lock.yaml +++ b/web/pnpm-lock.yaml @@ -306,9 +306,6 @@ importers: jsdom: specifier: ^26.1.0 version: 26.1.0 - pino: - specifier: ^10.4.0 - version: 10.4.0 react: specifier: ^19.1.0 version: 19.3.0 @@ -352,9 +349,6 @@ importers: jsdom: specifier: ^26.1.0 version: 26.1.0 - pino: - specifier: ^10.4.0 - version: 10.4.0 react: specifier: ^19.1.0 version: 19.3.0 diff --git a/web/service/shared/health.test.ts b/web/service/shared/health.test.ts index b85c96d6a..2cbc6ae85 100644 --- a/web/service/shared/health.test.ts +++ b/web/service/shared/health.test.ts @@ -1,18 +1,17 @@ import { describe, expect, it, vi } from "vitest"; -import type { Logger } from "pino"; import { createNextHealthRoute } from "./health"; -function recordingLogger() { - const error = vi.fn(); - const logger = { child: () => logger, debug: vi.fn(), info: vi.fn(), warn: vi.fn(), error } as unknown as Logger; - return { logger, error }; -} - describe("createNextHealthRoute", () => { + it("still returns unavailable if log delivery throws", async () => { + const GET = createNextHealthRoute( + { gateway: () => { throw new Error("gateway unavailable"); } }, + () => { throw new Error("logging unavailable"); }, + ); + expect((await GET()).status).toBe(503); + }); it("is ready and uncached when every check passes", async () => { - const { logger } = recordingLogger(); - const response = await createNextHealthRoute({ configuration: () => {}, gateway: async () => {} }, logger)(); + const response = await createNextHealthRoute({ configuration: () => {}, gateway: async () => {} })(); expect(response.status).toBe(200); expect(response.headers.get("cache-control")).toBe("no-store"); await expect(response.json()).resolves.toEqual({ status: "ok" }); @@ -23,16 +22,16 @@ describe("createNextHealthRoute", () => { const gateway = vi.fn().mockRejectedValueOnce(cause).mockRejectedValueOnce(cause) .mockResolvedValueOnce(undefined).mockRejectedValueOnce(cause); const later = vi.fn(); - const { logger, error } = recordingLogger(); - const GET = createNextHealthRoute({ gateway, later }, logger); + const onLog = vi.fn(); + const GET = createNextHealthRoute({ gateway, later }, onLog); expect((await GET()).status).toBe(503); expect((await GET()).status).toBe(503); - expect(error).toHaveBeenCalledOnce(); - expect(error).toHaveBeenCalledWith({ check: "gateway", err: cause }, "Web readiness check failed"); + expect(onLog).toHaveBeenCalledOnce(); + expect(onLog).toHaveBeenCalledWith("error", "Web readiness check failed", { check: "gateway", error: cause }); expect(later).not.toHaveBeenCalled(); expect((await GET()).status).toBe(200); expect((await GET()).status).toBe(503); - expect(error).toHaveBeenCalledTimes(2); + expect(onLog).toHaveBeenCalledTimes(2); }); }); diff --git a/web/service/shared/health.ts b/web/service/shared/health.ts index 9861c871e..bde3e8fd7 100644 --- a/web/service/shared/health.ts +++ b/web/service/shared/health.ts @@ -1,4 +1,4 @@ -import type { Logger } from "pino"; +import { createLogCallback, type LogCallback } from "@submitqueue/web-platform/logging"; export type HealthChecks = Readonly void | Promise>>; @@ -9,8 +9,9 @@ const NO_STORE = { "Cache-Control": "no-store" }; * when all pass, otherwise 503. Each check's failure is logged once until it * recovers, so a polling orchestrator does not flood the logs. */ -export function createNextHealthRoute(checks: HealthChecks, logger: Logger) { +export function createNextHealthRoute(checks: HealthChecks, onLog?: LogCallback) { const failing = new Set(); + const log = createLogCallback(onLog); return async function GET(): Promise { for (const [name, check] of Object.entries(checks)) { try { @@ -18,7 +19,7 @@ export function createNextHealthRoute(checks: HealthChecks, logger: Logger) { } catch (cause) { if (!failing.has(name)) { failing.add(name); - logger.error({ check: name, err: cause }, "Web readiness check failed"); + log("error", "Web readiness check failed", { check: name, error: cause }); } return Response.json({ status: "unavailable" }, { status: 503, headers: NO_STORE }); } diff --git a/web/service/shared/logging.test.ts b/web/service/shared/logging.test.ts new file mode 100644 index 000000000..7f1414fd2 --- /dev/null +++ b/web/service/shared/logging.test.ts @@ -0,0 +1,32 @@ +import { describe, expect, it } from "vitest"; +import { pino } from "pino"; +import { createPinoLogCallback } from "./logging.js"; + +describe("Pino log delivery", () => { + it("preserves severity, message, metadata and the serialized error stack", () => { + const lines: string[] = []; + const log = createPinoLogCallback( + pino({ level: "info" }, { + write: (line) => { lines.push(line); }, + }), + ); + const error = new Error("backend unavailable"); + log("info", "Access denied", { requestId: "request-1" }); + log("warn", "Backend call failed", { requestId: "request-2", error }); + log("error", "Page load failed", { requestId: "request-3", error }); + + const entries = lines.map((line) => JSON.parse(line)); + expect(entries).toMatchObject([ + { level: 30, msg: "Access denied", requestId: "request-1" }, + { + level: 40, msg: "Backend call failed", requestId: "request-2", + err: { message: error.message, stack: error.stack }, + }, + { + level: 50, msg: "Page load failed", requestId: "request-3", + err: { message: error.message, stack: error.stack }, + }, + ]); + expect(entries[1]).not.toHaveProperty("error"); + }); +}); diff --git a/web/service/shared/logging.ts b/web/service/shared/logging.ts new file mode 100644 index 000000000..f3f44759c --- /dev/null +++ b/web/service/shared/logging.ts @@ -0,0 +1,9 @@ +import type { LogCallback } from "@submitqueue/web-platform/logging"; +import type { Logger } from "pino"; + +export function createPinoLogCallback(logger: Logger): LogCallback { + return (level, message, metadata) => { + const { error, ...fields } = metadata; + logger[level]("error" in metadata ? { ...fields, err: error } : fields, message); + }; +} diff --git a/web/service/shared/package.json b/web/service/shared/package.json index 8ce7a5d8e..8f97076b0 100644 --- a/web/service/shared/package.json +++ b/web/service/shared/package.json @@ -46,6 +46,10 @@ "types": "./dist/transport.d.ts", "import": "./dist/transport.js" }, + "./logging": { + "types": "./dist/logging.d.ts", + "import": "./dist/logging.js" + }, "./health": { "types": "./dist/health.d.ts", "import": "./dist/health.js" diff --git a/web/service/stovepipe/src/app/healthz/route.ts b/web/service/stovepipe/src/app/healthz/route.ts index 62751e408..3e83127a8 100644 --- a/web/service/stovepipe/src/app/healthz/route.ts +++ b/web/service/stovepipe/src/app/healthz/route.ts @@ -4,7 +4,7 @@ import { createNextHealthRoute } from "@submitqueue/web-service-shared/health"; import { loadConfiguration } from "../../server/config"; import { loadAuthConfiguration } from "../../server/auth"; import { newConnectTransport } from "@submitqueue/web-service-shared/transport"; -import { logger } from "../../server/host"; +import { onLog } from "../../server/host"; export const dynamic = "force-dynamic"; @@ -25,5 +25,5 @@ export const GET = createNextHealthRoute( await client.ping({ message: "stovepipe-web-readiness" }); }, }, - logger, + onLog, ); diff --git a/web/service/stovepipe/src/next/page.tsx b/web/service/stovepipe/src/next/page.tsx index a2d29586e..64e0cea5d 100644 --- a/web/service/stovepipe/src/next/page.tsx +++ b/web/service/stovepipe/src/next/page.tsx @@ -1,6 +1,6 @@ import { forbidden, notFound, redirect } from "next/navigation"; import { requireAuthorization } from "./authorize"; -import { resolveHost } from "../server/host"; +import { onLog, resolveHost } from "../server/host"; import { StovepipeApp } from "@submitqueue/web-stovepipe"; import { NextNavigationProvider } from "@submitqueue/web-service-shared/navigation"; export async function StovepipePage({ @@ -22,6 +22,7 @@ export async function StovepipePage({ const result = await resolveHost().handle({ path: `/${path.join("/")}`, search, + onLog, }); if (result.kind === "not-found") notFound(); if (result.kind === "forbidden") forbidden(); diff --git a/web/service/stovepipe/src/server/host.ts b/web/service/stovepipe/src/server/host.ts index 8ec309cd8..03af5eb76 100644 --- a/web/service/stovepipe/src/server/host.ts +++ b/web/service/stovepipe/src/server/host.ts @@ -3,12 +3,14 @@ import { createClient } from "@connectrpc/connect"; import { Stovepipe } from "@submitqueue/api/stovepipe"; import { createStovepipeWeb } from "@submitqueue/web-stovepipe/server"; import { pino } from "pino"; +import { createPinoLogCallback } from "@submitqueue/web-service-shared/logging"; import { loadConfiguration } from "./config"; import { newConnectTransport } from "@submitqueue/web-service-shared/transport"; -export const logger = pino({ +const logger = pino({ name: "stovepipe-web", level: process.env.LOG_LEVEL ?? "info", }); +export const onLog = createPinoLogCallback(logger); let host: ReturnType | undefined; export function resolveHost() { @@ -21,7 +23,6 @@ export function resolveHost() { host = createStovepipeWeb({ service, queues: configuration.queues, - logger, }); } return host; diff --git a/web/service/submitqueue/src/app/(protected)/[[...path]]/page.tsx b/web/service/submitqueue/src/app/(protected)/[[...path]]/page.tsx index f8507cb38..ac1612ce4 100644 --- a/web/service/submitqueue/src/app/(protected)/[[...path]]/page.tsx +++ b/web/service/submitqueue/src/app/(protected)/[[...path]]/page.tsx @@ -1,11 +1,16 @@ import { createNextPage } from "../../../next/page"; import { resolveReferenceWeb } from "../../../server/host"; import { requireAuthorization } from "../../../next/authorize"; +import { resolveReferenceLogCallback } from "../../../server/observability"; export const dynamic = "force-dynamic"; export const revalidate = 0; -const page = createNextPage({ web: resolveReferenceWeb, authenticate: requireAuthorization }); +const page = createNextPage({ + web: resolveReferenceWeb, + authenticate: requireAuthorization, + onLog: resolveReferenceLogCallback(), +}); export const generateMetadata = page.generateMetadata; export default page.Page; diff --git a/web/service/submitqueue/src/app/healthz/route.ts b/web/service/submitqueue/src/app/healthz/route.ts index 118defcba..ede5dfec3 100644 --- a/web/service/submitqueue/src/app/healthz/route.ts +++ b/web/service/submitqueue/src/app/healthz/route.ts @@ -2,7 +2,7 @@ import { createNextHealthRoute } from "@submitqueue/web-service-shared/health"; import { loadAuthConfiguration } from "../../server/auth"; import { loadCursorSecret, loadGatewayConfiguration } from "../../server/config"; import { pingReferenceGateway } from "../../server/gateway"; -import { resolveReferenceLogger } from "../../server/observability"; +import { resolveReferenceLogCallback } from "../../server/observability"; export const dynamic = "force-dynamic"; @@ -13,4 +13,4 @@ export const GET = createNextHealthRoute({ loadGatewayConfiguration(); }, gateway: pingReferenceGateway, -}, resolveReferenceLogger()); +}, resolveReferenceLogCallback()); diff --git a/web/service/submitqueue/src/next/page.tsx b/web/service/submitqueue/src/next/page.tsx index 64fa3fcd3..6e4197374 100644 --- a/web/service/submitqueue/src/next/page.tsx +++ b/web/service/submitqueue/src/next/page.tsx @@ -3,7 +3,7 @@ import { forbidden, notFound, redirect } from "next/navigation"; import { connection } from "next/server"; import { cache } from "react"; import { SubmitQueueApp } from "@submitqueue/web-submitqueue"; -import type { SubmitQueueWeb, WebSearchParams } from "@submitqueue/web-submitqueue/server"; +import type { SubmitQueueWeb, SubmitQueueWebRequest, WebSearchParams } from "@submitqueue/web-submitqueue/server"; import { NextNavigationProvider } from "@submitqueue/web-service-shared/navigation"; export interface NextPageProps { @@ -19,6 +19,7 @@ export interface NextPageOptions { * It may call Next's `unauthorized()`; it runs before every load. */ authenticate?: () => Promise; + onLog?: SubmitQueueWebRequest["onLog"]; } /** @@ -36,6 +37,7 @@ export function createNextPage(options: NextPageOptions) { return web.handle({ path, search: JSON.parse(encodedSearch) as WebSearchParams, ...(principal === undefined ? {} : { principal }), + ...(options.onLog ? { onLog: options.onLog } : {}), }); }); diff --git a/web/service/submitqueue/src/server/host.ts b/web/service/submitqueue/src/server/host.ts index 5c1314ca8..36593d63d 100644 --- a/web/service/submitqueue/src/server/host.ts +++ b/web/service/submitqueue/src/server/host.ts @@ -4,7 +4,7 @@ import { newHmacCursorCodec } from "@submitqueue/web-submitqueue/extension/curso import { createSubmitQueueWeb, type SubmitQueueWeb } from "@submitqueue/web-submitqueue/server"; import { loadCursorSecret } from "./config"; import { resolveReferenceGateway } from "./gateway"; -import { resolveReferenceLogger, resolveReferenceMeter } from "./observability"; +import { resolveReferenceMeter } from "./observability"; let web: SubmitQueueWeb | undefined; @@ -17,7 +17,6 @@ export function resolveReferenceWeb(): SubmitQueueWeb { web ??= createSubmitQueueWeb({ gateway: resolveReferenceGateway, cursors: newHmacCursorCodec(loadCursorSecret()), - logger: resolveReferenceLogger(), meter: resolveReferenceMeter(), }); return web; diff --git a/web/service/submitqueue/src/server/observability.ts b/web/service/submitqueue/src/server/observability.ts index 0cfae1b08..d3ab512fd 100644 --- a/web/service/submitqueue/src/server/observability.ts +++ b/web/service/submitqueue/src/server/observability.ts @@ -4,6 +4,7 @@ import { metrics, type Meter } from "@opentelemetry/api"; import { PrometheusExporter } from "@opentelemetry/exporter-prometheus"; import { MeterProvider } from "@opentelemetry/sdk-metrics"; import { pino, type Logger } from "pino"; +import { createPinoLogCallback } from "@submitqueue/web-service-shared/logging"; import { loadMetricsPort } from "./config"; let logger: Logger | undefined; @@ -14,6 +15,10 @@ export function resolveReferenceLogger(): Logger { return logger; } +export function resolveReferenceLogCallback() { + return createPinoLogCallback(resolveReferenceLogger()); +} + let meter: Meter | undefined; /** diff --git a/web/stovepipe/BUILD.bazel b/web/stovepipe/BUILD.bazel index 779c46086..8e53b7db2 100644 --- a/web/stovepipe/BUILD.bazel +++ b/web/stovepipe/BUILD.bazel @@ -28,7 +28,6 @@ web_library( ":node_modules/@submitqueue/web-platform", ":node_modules/@types/node", ":node_modules/@types/react", - ":node_modules/pino", ":node_modules/react", ], ) diff --git a/web/stovepipe/README.md b/web/stovepipe/README.md index e17926426..723edc7c2 100644 --- a/web/stovepipe/README.md +++ b/web/stovepipe/README.md @@ -2,6 +2,8 @@ A framework-neutral React UI with a queue request list and a request page containing the current lifecycle summary and retained history. The host supplies queue configuration, a structural `StovepipeService` client, authentication, transport, logging and OpenTelemetry providers. +Logging uses a synchronous `onLog` callback passed on each `handle` request. Bind it to the host's request-scoped logger; it receives severity, message, and structured metadata containing the original `error`, correlation `requestId`, and page `path`. Omitting it is silent, and callback exceptions do not change page results. The library has no logging-library dependency. + ## Integration Use the server entry's `createStovepipeWeb` to load a page and render its model with `StovepipeApp`. Mount beneath `WebNavigationProvider` when the host supplies client navigation and refresh. Without it, links and refresh use ordinary document navigation. Import `@submitqueue/web-stovepipe/styles.css`, which includes the common native styles from `@submitqueue/web-platform`. diff --git a/web/stovepipe/controller/page.ts b/web/stovepipe/controller/page.ts index a0688e0dd..fba376caa 100644 --- a/web/stovepipe/controller/page.ts +++ b/web/stovepipe/controller/page.ts @@ -1,15 +1,15 @@ -import type { Logger } from "pino"; +import { createLogCallback, type LogCallback } from "@submitqueue/web-platform/logging"; import type { ReadResult } from "../entity/index.js"; export async function readSection( operation: () => Promise, - logger: Logger, + onLog: LogCallback | undefined, section: string, ): Promise> { try { return { ok: true, data: await operation() }; } catch (err) { - logger.warn({ err, section }, "Stovepipe page section failed"); + createLogCallback(onLog)("warn", "Stovepipe page section failed", { error: err, section }); return { ok: false, error: `Unable to load ${section}. Try refreshing. If the problem continues, check that the request exists and that the service is available.`, diff --git a/web/stovepipe/module.test.ts b/web/stovepipe/module.test.ts index 23f63db10..0f888a636 100644 --- a/web/stovepipe/module.test.ts +++ b/web/stovepipe/module.test.ts @@ -42,6 +42,76 @@ function createPageTestContext() { return { service, paths, app }; } describe("Stovepipe page loading", () => { + it("keeps overlapping loads bound to their own host logging callbacks", async () => { + const { app, service, paths } = createPageTestContext(); + let release!: () => void; + const ready = new Promise((resolve) => { + release = resolve; + }); + const error = new Error("private upstream detail"); + vi.mocked(service.list).mockImplementation(async () => { + await ready; + throw error; + }); + const first = vi.fn(); + const second = vi.fn(); + const path = paths.queue("repo/main"); + const pending = [ + app.handle({ + path, search: new URLSearchParams(), + requestId: "first", onLog: first, + }), + app.handle({ + path, search: new URLSearchParams(), + requestId: "second", onLog: second, + }), + ]; + release(); + const results = await Promise.all(pending); + + expect(first).toHaveBeenCalledOnce(); + expect(second).toHaveBeenCalledOnce(); + expect(first).toHaveBeenCalledWith("warn", "Stovepipe page section failed", { + requestId: "first", path, section: "queue requests", error, + }); + expect(second).toHaveBeenCalledWith("warn", "Stovepipe page section failed", { + requestId: "second", path, section: "queue requests", error, + }); + expect(JSON.stringify(results)).not.toContain("private upstream detail"); + }); + + it("retains the page result when log delivery throws", async () => { + const { app, service, paths } = createPageTestContext(); + vi.mocked(service.list).mockRejectedValue(new Error("private upstream detail")); + const result = await app.handle({ + path: paths.queue("repo/main"), search: new URLSearchParams(), + onLog: () => { + throw new Error("logging unavailable"); + }, + }); + expect(result).toMatchObject({ kind: "render", model: { requests: { ok: false } } }); + expect(JSON.stringify(result)).not.toContain("private upstream detail"); + }); + + it("reports and rethrows unexpected page failures without replacing the cause", async () => { + const { service, paths } = createPageTestContext(); + const error = new Error("invalid host configuration"); + const onLog = vi.fn(() => { + throw new Error("logging unavailable"); + }); + const app = createStovepipeWeb({ + service: () => { throw error; }, + paths, + queues: [{ name: "repo/main" }], + }); + const path = paths.queue("repo/main"); + await expect(app.handle({ + path, search: new URLSearchParams(), requestId: "failed", onLog, + })).rejects.toBe(error); + expect(onLog).toHaveBeenCalledWith("error", "Web page load failed", { + requestId: "failed", path, error, + }); + }); it("uses backend queue cursors and links each request by its ID", async () => { const { service, app, paths } = createPageTestContext(); vi.mocked(service.list).mockResolvedValue({ diff --git a/web/stovepipe/module.ts b/web/stovepipe/module.ts index bf1e4e740..f2ee5d2ea 100644 --- a/web/stovepipe/module.ts +++ b/web/stovepipe/module.ts @@ -1,5 +1,5 @@ -import { metrics, trace, type Meter, type Tracer } from "@opentelemetry/api"; -import { pino, type Logger } from "pino"; +import { metrics, trace, SpanStatusCode, type Meter, type Tracer } from "@opentelemetry/api"; +import { createLogCallback, type LogCallback } from "@submitqueue/web-platform/logging"; import { parseStovepipeRoute } from "./core/route.js"; import type { StovepipeService } from "./extension/service/index.js"; import type { Queue, StovepipePageModel } from "./entity/index.js"; @@ -14,6 +14,10 @@ export interface StovepipeWebRequest { search: URLSearchParams; principal?: unknown; signal?: AbortSignal; + /** Correlation ID for logs; generated when absent. */ + requestId?: string; + /** Host callback bound to this request's logging context; absent means silent. */ + onLog?: LogCallback; } export type StovepipeWebResult = | { kind: "render"; model: StovepipePageModel } @@ -27,13 +31,11 @@ export interface StovepipeWebOptions { queues: readonly Queue[]; paths?: StovepipePaths; authorize?(principal: unknown, queue: string): boolean | Promise; - logger?: Logger; meter?: Meter; tracer?: Tracer; } export function createStovepipeWeb(options: StovepipeWebOptions) { const paths = options.paths ?? new StovepipePaths(); - const logger = options.logger ?? pino({ enabled: false }); const meter = options.meter ?? metrics.getMeter("stovepipe-web"); const tracer = options.tracer ?? trace.getTracer("stovepipe-web"); const loads = meter.createCounter("stovepipe.web.page_loads"); @@ -43,6 +45,10 @@ export function createStovepipeWeb(options: StovepipeWebOptions) { return { async handle(request: StovepipeWebRequest): Promise { const started = Date.now(); + const onLog = createLogCallback(request.onLog, { + requestId: request.requestId ?? globalThis.crypto.randomUUID(), + path: request.path, + }); return tracer.startActiveSpan( "stovepipe.web.page_load", async (span): Promise => { @@ -93,7 +99,7 @@ export function createStovepipeWeb(options: StovepipeWebOptions) { request.search.get("page") ?? "", request.signal, ), - logger, + onLog, "queue requests", ); return { @@ -110,7 +116,7 @@ export function createStovepipeWeb(options: StovepipeWebOptions) { requestId, request.signal, ), - logger, + onLog, "request history", ); return { @@ -122,6 +128,11 @@ export function createStovepipeWeb(options: StovepipeWebOptions) { history, }, }; + } catch (error) { + onLog("error", "Web page load failed", { error }); + span.recordException(error instanceof Error ? error : String(error)); + span.setStatus({ code: SpanStatusCode.ERROR }); + throw error; } finally { loads.add(1); latency.record(Date.now() - started); diff --git a/web/stovepipe/package.json b/web/stovepipe/package.json index 4e1b2e8ab..981449d42 100644 --- a/web/stovepipe/package.json +++ b/web/stovepipe/package.json @@ -29,7 +29,6 @@ }, "peerDependencies": { "@opentelemetry/api": ">=1.9 <2", - "pino": ">=10 <11", "react": ">=18 <20" }, "devDependencies": { @@ -40,7 +39,6 @@ "@types/react": "^19.1.0", "@types/react-dom": "^19.1.0", "jsdom": "^26.1.0", - "pino": "^10.4.0", "react": "^19.1.0", "react-dom": "^19.1.0", "typescript": "^5.8.3", diff --git a/web/submitqueue/BUILD.bazel b/web/submitqueue/BUILD.bazel index fd0ba6d2e..5db0fd3f9 100644 --- a/web/submitqueue/BUILD.bazel +++ b/web/submitqueue/BUILD.bazel @@ -29,7 +29,6 @@ web_library( ":node_modules/@submitqueue/web-platform", ":node_modules/@types/node", ":node_modules/@types/react", - ":node_modules/pino", ":node_modules/react", ], ) diff --git a/web/submitqueue/README.md b/web/submitqueue/README.md index a87b14483..ba95102ca 100644 --- a/web/submitqueue/README.md +++ b/web/submitqueue/README.md @@ -14,7 +14,9 @@ The complete read-only SubmitQueue UI as a mountable module. Folders follow the Entry points: the root is client-safe (`SubmitQueueApp`, page frames, `WebNavigationProvider`, model types); `./server` has `createSubmitQueueWeb`, the gateway and cursor contracts, and `WebPaths`; `./extension/cursor/hmac` signs cursors; `./extension/gateway/mock` has test fakes; `./styles.css` is the full stylesheet. Controllers and helpers stay internal. -**Hosting it.** Give `createSubmitQueueWeb` a gateway client (any client matching the structural contract, so the module ships no generated code), a `CursorCodec`, and optionally a mount path, authorization check, logger, meter, tracer, error classifier, or cached queue catalog. Route every page path to `handle`, render `SubmitQueueApp` with each page model, and wrap it in a `WebNavigationProvider` for client-side navigation. Hosts must load `./styles.css`, either by importing it or by serving it and linking to it; theme with the `--sq-*` properties. +**Hosting it.** Give `createSubmitQueueWeb` a gateway client (any client matching the structural contract, so the module ships no generated code), a `CursorCodec`, and optionally a mount path, authorization check, meter, tracer, error classifier, or cached queue catalog. Route every page path to `handle`, render `SubmitQueueApp` with each page model, and wrap it in a `WebNavigationProvider` for client-side navigation. Hosts must load `./styles.css`, either by importing it or by serving it and linking to it; theme with the `--sq-*` properties. + +Pass `onLog` on each `handle` request to deliver severity, message, and structured metadata to the host's request-scoped logger. Errors retain their original value under `error`, and logs include the correlation `requestId` and page `path`. The callback must be synchronous; omitting it is silent, and callback exceptions do not change page results. The module has no logging-library dependency. **Behavior worth knowing.** Expected outcomes (missing resources, stale cursors) are results, never exceptions. Raw gateway errors are logged, never rendered. Views keep the last good data on transient failures. Request IDs stay opaque in URLs; dot-only segments get a visible `~` escape. diff --git a/web/submitqueue/controller/controller.test.ts b/web/submitqueue/controller/controller.test.ts index da0bd4056..7733da6ac 100644 --- a/web/submitqueue/controller/controller.test.ts +++ b/web/submitqueue/controller/controller.test.ts @@ -1,5 +1,4 @@ import { Code, ConnectError } from "@connectrpc/connect"; -import type { Logger } from "pino"; import { beforeEach, describe, expect, it, vi } from "vitest"; import { createFakeGatewayReader, gatewayHistoryFixture, gatewayRequestFixture } from "../extension/gateway/mock/index.js"; @@ -14,12 +13,6 @@ import { loadRequestDetail, requestDetailIsComplete, requestDetailRefreshState } const FAILURE_MESSAGE = "SubmitQueue gateway call failed"; -function recordingLogger() { - const warn = vi.fn(); - const logger = { child: () => logger, debug: vi.fn(), info: vi.fn(), warn, error: vi.fn() } as unknown as Logger; - return { logger, warn }; -} - describe("queue discovery mapping", () => { it("lists gateway-configured queues, including ones without requests", async () => { const reader = createFakeGatewayReader({ queues: [{ name: "demo-queue" }, { name: "empty-queue" }] }); @@ -34,15 +27,15 @@ describe("queue discovery mapping", () => { }); it("classifies discovery failures without leaking the gateway message", async () => { - const { logger, warn } = recordingLogger(); + const onLog = vi.fn(); const cause = new ConnectError("private upstream detail", Code.Unavailable); const result = await loadQueueDirectory( createFakeGatewayReader({ queuesError: cause }), - { logger }, + { onLog }, ); expect(result).toMatchObject({ ok: false, error: { kind: "transient", retryable: true } }); expect(JSON.stringify(result)).not.toContain("private upstream detail"); - expect(warn).toHaveBeenCalledWith(expect.objectContaining({ operation: "queues", err: cause }), FAILURE_MESSAGE); + expect(onLog).toHaveBeenCalledWith("warn", FAILURE_MESSAGE, expect.objectContaining({ operation: "queues", error: cause })); }); it.each([{ queues: [{ name: "" }] }, { queues: [{ name: "same" }, { name: "same" }] }])("rejects malformed discovery data", async ({ queues }) => { @@ -129,7 +122,7 @@ describe("server presentation mapping", () => { }); it("keeps the summary available when history has a transient failure", async () => { - const { logger, warn } = recordingLogger(); + const onLog = vi.fn(); const historyCause = new ConnectError("private upstream text", Code.Unavailable); const reader = createFakeGatewayReader({ summary: gatewayRequestFixture({ status: "landed" }), @@ -141,7 +134,7 @@ describe("server presentation mapping", () => { queue: "demo-queue", sqid: "demo-queue/1", }, - { logger }, + { onLog }, ); expect(result).toMatchObject({ @@ -152,13 +145,13 @@ describe("server presentation mapping", () => { historyError: { kind: "transient", retryable: true }, }, }); - expect(warn).toHaveBeenCalledWith({ + expect(onLog).toHaveBeenCalledWith("warn", FAILURE_MESSAGE, { operation: "history", queue: "demo-queue", sqid: "demo-queue/1", code: "unavailable", - err: historyCause, - }, FAILURE_MESSAGE); + error: historyCause, + }); expect(JSON.stringify(result)).not.toContain("private upstream text"); if (result.ok) { expect(requestDetailIsComplete(result.data)).toBe(false); @@ -238,6 +231,14 @@ describe("server presentation mapping", () => { }); describe("gateway error classification", () => { + it("returns the sanitized upstream error even when log delivery throws", async () => { + const result = await loadQueueDirectory( + createFakeGatewayReader({ queuesError: new ConnectError("private upstream detail", Code.Unavailable) }), + { onLog: () => { throw new Error("logging unavailable"); } }, + ); + expect(result).toMatchObject({ ok: false, error: { kind: "transient", retryable: true } }); + expect(JSON.stringify(result)).not.toContain("private upstream detail"); + }); it.each([ [Code.InvalidArgument, "user", false], [Code.NotFound, "not-found", false], @@ -253,25 +254,25 @@ describe("gateway error classification", () => { }); it("uses a host classifier for transports without gRPC status codes", async () => { - const { logger, warn } = recordingLogger(); + const onLog = vi.fn(); const result = await loadRequestList( createFakeGatewayReader({ listError: new Error("custom transport: upstream timed out") }), { queue: "demo-queue", receivedAtOrAfterMs: 100, receivedBeforeMs: 200 }, - { classifyError: () => "unavailable", logger }, + { classifyError: () => "unavailable", onLog }, ); expect(result).toMatchObject({ ok: false, error: { kind: "transient", retryable: true } }); - expect(warn).toHaveBeenCalledWith(expect.objectContaining({ code: "unavailable" }), FAILURE_MESSAGE); + expect(onLog).toHaveBeenCalledWith("warn", FAILURE_MESSAGE, expect.objectContaining({ code: "unavailable" })); }); it("treats a throwing host classifier as an internal failure", async () => { - const { logger, warn } = recordingLogger(); + const onLog = vi.fn(); const result = await loadRequestList( createFakeGatewayReader({ listError: new Error("upstream") }), { queue: "demo-queue", receivedAtOrAfterMs: 100, receivedBeforeMs: 200 }, - { classifyError: () => { throw new Error("classifier bug"); }, logger }, + { classifyError: () => { throw new Error("classifier bug"); }, onLog }, ); expect(result).toMatchObject({ ok: false, error: { kind: "internal", retryable: false } }); - expect(warn).toHaveBeenCalledWith(expect.objectContaining({ code: "internal" }), FAILURE_MESSAGE); + expect(onLog).toHaveBeenCalledWith("warn", FAILURE_MESSAGE, expect.objectContaining({ code: "internal" })); }); it("does not expose arbitrary errors", () => { @@ -283,7 +284,7 @@ describe("gateway error classification", () => { it("logs one structured failure without exposing the cause", async () => { const cause = new ConnectError("private upstream detail", Code.Unavailable); - const { logger, warn } = recordingLogger(); + const onLog = vi.fn(); const result = await loadRequestList( createFakeGatewayReader({ listError: cause }), { @@ -291,11 +292,11 @@ describe("gateway error classification", () => { receivedAtOrAfterMs: 100, receivedBeforeMs: 200, }, - { logger }, + { onLog }, ); - expect(warn).toHaveBeenCalledOnce(); - expect(warn).toHaveBeenCalledWith({ operation: "list", queue: "demo-queue", code: "unavailable", err: cause }, FAILURE_MESSAGE); + expect(onLog).toHaveBeenCalledOnce(); + expect(onLog).toHaveBeenCalledWith("warn", FAILURE_MESSAGE, { operation: "list", queue: "demo-queue", code: "unavailable", error: cause }); expect(JSON.stringify(result)).not.toContain("private upstream detail"); }); }); diff --git a/web/submitqueue/controller/gateway-call.ts b/web/submitqueue/controller/gateway-call.ts index 33ab08eff..e2a2d6c91 100644 --- a/web/submitqueue/controller/gateway-call.ts +++ b/web/submitqueue/controller/gateway-call.ts @@ -1,7 +1,7 @@ import { SpanStatusCode, type Meter, type Span, type Tracer } from "@opentelemetry/api"; import type { WebError } from "../entity/index.js"; -import { beginOperation, defaultMeter, defaultTracer, silentLogger } from "../core/observability.js"; -import type { Logger } from "pino"; +import { beginOperation, defaultMeter, defaultTracer } from "../core/observability.js"; +import { createLogCallback, type LogCallback } from "@submitqueue/web-platform/logging"; import type { GatewayErrorClassifier, GatewayErrorCode } from "../extension/gateway/index.js"; import { grpcStatusErrorCode } from "../extension/gateway/grpcstatus/index.js"; import { webErrorForGatewayCode } from "./error.js"; @@ -12,7 +12,7 @@ export interface GatewayLoadOptions { /** Maps transport errors to codes; defaults to {@link grpcStatusErrorCode}. */ classifyError?: GatewayErrorClassifier; /** Receives one warning per failed call, with the raw cause. */ - logger?: Logger; + onLog?: LogCallback; meter?: Meter; tracer?: Tracer; } @@ -50,7 +50,7 @@ export async function callGateway( const code = classifyGatewayError(options.classifyError ?? grpcStatusErrorCode, cause); timing.end(code); span.setStatus({ code: SpanStatusCode.ERROR, message: code }); - (options.logger ?? silentLogger).warn({ operation, ...target, code, err: cause }, "SubmitQueue gateway call failed"); + createLogCallback(options.onLog)("warn", "SubmitQueue gateway call failed", { operation, ...target, code, error: cause }); return { ok: false, error: webErrorForGatewayCode(code) }; } finally { span.end(); diff --git a/web/submitqueue/core/observability.test.ts b/web/submitqueue/core/observability.test.ts index 05d822c53..af935c574 100644 --- a/web/submitqueue/core/observability.test.ts +++ b/web/submitqueue/core/observability.test.ts @@ -1,7 +1,7 @@ import type { Meter } from "@opentelemetry/api"; import { describe, expect, it, vi } from "vitest"; -import { beginOperation, silentLogger } from "./observability.js"; +import { beginOperation } from "./observability.js"; describe("beginOperation", () => { it("records one duration tagged with the start attributes and outcome", () => { @@ -15,9 +15,3 @@ describe("beginOperation", () => { expect(record).toHaveBeenCalledWith(expect.any(Number), { page: "queue", module: "submitqueue", outcome: "success" }); }); }); - -describe("silentLogger", () => { - it("discards entries, including from child loggers", () => { - expect(silentLogger.child({ requestId: "1" }).isLevelEnabled("fatal")).toBe(false); - }); -}); diff --git a/web/submitqueue/core/observability.ts b/web/submitqueue/core/observability.ts index 00b46847f..069d4ee42 100644 --- a/web/submitqueue/core/observability.ts +++ b/web/submitqueue/core/observability.ts @@ -1,8 +1,4 @@ import { metrics, trace, type Attributes, type Meter, type Tracer } from "@opentelemetry/api"; -import { pino, type Logger } from "pino"; - -/** Discards every entry; the default when a host supplies no logger. */ -export const silentLogger: Logger = pino({ level: "silent" }); /** Instrumentation scope for meters and tracers the web packages create by default. */ export const INSTRUMENTATION_SCOPE = "submitqueue-web"; diff --git a/web/submitqueue/module.test.ts b/web/submitqueue/module.test.ts index 3bc506c8e..37241c8c2 100644 --- a/web/submitqueue/module.test.ts +++ b/web/submitqueue/module.test.ts @@ -1,8 +1,7 @@ import { Code, ConnectError } from "@connectrpc/connect"; import type { Meter } from "@opentelemetry/api"; -import type { Logger } from "pino"; import { describe, expect, it, vi } from "vitest"; -import { createSubmitQueueWeb, type SubmitQueueWebOptions } from "./module.js"; +import { createSubmitQueueWeb, type SubmitQueueWebOptions, type SubmitQueueWebRequest } from "./module.js"; import { createFakeGatewayReader, gatewayHistoryFixture, gatewayRequestFixture } from "./extension/gateway/mock/index.js"; import type { SubmitQueueGateway } from "./extension/gateway/index.js"; import { newHmacCursorCodec } from "./extension/cursor/hmac/index.js"; @@ -19,7 +18,7 @@ const githubPath = "/sq/demo-queue/change/github/github.com/uber/submitqueue/pul function newWeb(options: Partial = {}) { const web = createSubmitQueueWeb({ gateway: createFakeGatewayReader(), cursors, paths, ...options }); - return (path: string, search: Record = {}, extra: { principal?: unknown; requestId?: string } = {}) => + return (path: string, search: Record = {}, extra: Pick = {}) => web.handle({ path, search, ...extra }); } @@ -28,14 +27,6 @@ function recordingMeter() { return { meter: { createHistogram: () => ({ record }) } as unknown as Meter, record }; } -function recordingLogger() { - const warn = vi.fn(); - const error = vi.fn(); - const child = vi.fn((): Logger => logger); - const logger = { child, debug: vi.fn(), info: vi.fn(), warn, error } as unknown as Logger; - return { logger, child, warn, error }; -} - function nextPageToken(result: Awaited>>): string { if (result.kind !== "render" || result.model.kind !== "queue" || !result.model.result.ok) { throw new Error("Expected a queue page"); @@ -217,13 +208,12 @@ describe("createSubmitQueueWeb", () => { it("logs upstream failures with the request ID while showing a sanitized error", async () => { const cause = new ConnectError("upstream failure", Code.Unavailable); - const { logger, child, warn } = recordingLogger(); - const get = newWeb({ gateway: createFakeGatewayReader({ queuesError: cause }), logger }); - expect(await get("/sq", {}, { requestId: "request-7" })).toMatchObject({ + const onLog = vi.fn(); + const get = newWeb({ gateway: createFakeGatewayReader({ queuesError: cause }) }); + expect(await get("/sq", {}, { requestId: "request-7", onLog })).toMatchObject({ kind: "render", model: { result: { ok: false, error: { kind: "transient" } } }, }); - expect(child).toHaveBeenCalledWith({ requestId: "request-7" }); - expect(warn).toHaveBeenCalledWith(expect.objectContaining({ operation: "queues", err: cause, code: "unavailable" }), expect.any(String)); + expect(onLog).toHaveBeenCalledWith("warn", expect.any(String), expect.objectContaining({ requestId: "request-7", operation: "queues", error: cause, code: "unavailable" })); }); it("records each page load's outcome", async () => { @@ -232,13 +222,46 @@ describe("createSubmitQueueWeb", () => { expect(record).toHaveBeenCalledWith(expect.any(Number), { page: "queue", outcome: "redirect" }); }); + it("keeps overlapping loads bound to their own host logging callbacks", async () => { + let release!: () => void; + const ready = new Promise(resolve => { release = resolve; }); + const cause = new ConnectError("private upstream detail", Code.Unavailable); + const gateway = createFakeGatewayReader(); + vi.spyOn(gateway, "listQueues").mockImplementation(async () => { + await ready; + throw cause; + }); + const first = vi.fn(); + const second = vi.fn(); + const get = newWeb({ gateway }); + const pending = [ + get("/sq", {}, { requestId: "first", onLog: first }), + get("/sq", {}, { requestId: "second", onLog: second }), + ]; + release(); + const results = await Promise.all(pending); + + expect(first).toHaveBeenCalledOnce(); + expect(second).toHaveBeenCalledOnce(); + expect(first).toHaveBeenCalledWith("warn", expect.any(String), expect.objectContaining({ requestId: "first", error: cause })); + expect(second).toHaveBeenCalledWith("warn", expect.any(String), expect.objectContaining({ requestId: "second", error: cause })); + expect(JSON.stringify(results)).not.toContain("private upstream detail"); + }); + + it("reports authorization decisions through the current request's callback", async () => { + const onLog = vi.fn(); + const get = newWeb({ authorize: () => false }); + expect(await get("/sq", {}, { requestId: "denied", onLog })).toEqual({ kind: "forbidden" }); + expect(onLog).toHaveBeenCalledWith("info", "Web page request was not authorized", { requestId: "denied", path: "/sq" }); + }); + it("logs, records, and rethrows an unexpected failure", async () => { const failure = new Error("bug"); - const { logger, error } = recordingLogger(); + const onLog = vi.fn(); const { meter, record } = recordingMeter(); - const get = newWeb({ gateway: () => { throw failure; }, logger, meter }); - await expect(get("/sq")).rejects.toBe(failure); - expect(error).toHaveBeenCalledWith(expect.objectContaining({ err: failure }), "Web page load failed"); + const get = newWeb({ gateway: () => { throw failure; }, meter }); + await expect(get("/sq", {}, { onLog })).rejects.toBe(failure); + expect(onLog).toHaveBeenCalledWith("error", "Web page load failed", expect.objectContaining({ error: failure })); expect(record).toHaveBeenCalledWith(expect.any(Number), { page: "queues", outcome: "exception" }); }); diff --git a/web/submitqueue/module.ts b/web/submitqueue/module.ts index 6e5e794e3..936dc8e8a 100644 --- a/web/submitqueue/module.ts +++ b/web/submitqueue/module.ts @@ -1,6 +1,6 @@ import { SpanStatusCode, type Meter, type Tracer } from "@opentelemetry/api"; -import type { Logger } from "pino"; -import { beginOperation, defaultMeter, defaultTracer, silentLogger } from "./core/observability.js"; +import { createLogCallback, type LogCallback } from "@submitqueue/web-platform/logging"; +import { beginOperation, defaultMeter, defaultTracer } from "./core/observability.js"; import { WebPaths } from "./core/paths.js"; import { parseRoute, type SubmitQueueWebRoute, type WebSearchParams } from "./core/route.js"; import { loadChangePage } from "./controller/change.js"; @@ -23,6 +23,8 @@ export interface SubmitQueueRequestContext { requestId?: string; /** Aborted when the viewer's request is abandoned. */ signal?: AbortSignal; + /** Logging callback scoped to this page load. */ + onLog?: LogCallback; } /** One page request, in framework-neutral terms. */ @@ -34,6 +36,8 @@ export interface SubmitQueueWebRequest { /** Correlation ID; generated when absent. */ requestId?: string; signal?: AbortSignal; + /** Host callback bound to this request's logging context; absent means silent. */ + onLog?: LogCallback; } /** Caches successful catalogs per key; the key must separate viewers whose gateway visibility differs. */ @@ -55,7 +59,6 @@ export interface SubmitQueueWebOptions { classifyError?: GatewayErrorClassifier; /** Caches the queue catalog (`ListQueues`) across loads; absent means every load reads it. */ queuesCache?: QueueCatalogCache; - logger?: Logger; meter?: Meter; tracer?: Tracer; now?: () => number; @@ -106,7 +109,6 @@ export function createSubmitQueueWeb(options: SubmitQueueWebOptions): SubmitQueu const paths = options.paths ?? new WebPaths(); const mount = paths.basePath.split("/").filter(Boolean); const now = () => options.now?.() ?? Date.now(); - const logger = options.logger ?? silentLogger; const meter = options.meter ?? defaultMeter(); const tracer = options.tracer ?? defaultTracer(); const newRequestId = options.newRequestId ?? (() => globalThis.crypto.randomUUID()); @@ -116,12 +118,18 @@ export function createSubmitQueueWeb(options: SubmitQueueWebOptions): SubmitQueu tracer, }; const readQueues: QueueCatalogLoader = (gateway, context) => - loadQueueDirectory(gateway, { ...baseGatewayOptions, logger: logger.child({ requestId: context.requestId }) }); + loadQueueDirectory(gateway, { + ...baseGatewayOptions, + ...(context.onLog ? { onLog: context.onLog } : {}), + }); const loadQueues = options.queuesCache ? cacheQueueCatalog(readQueues, options.queuesCache, now) : readQueues; async function load(route: SubmitQueueWebRoute, context: SubmitQueueRequestContext): Promise { const gateway = typeof options.gateway === "function" ? options.gateway(context) : options.gateway; - const gatewayOptions = { ...baseGatewayOptions, logger: logger.child({ requestId: context.requestId }) }; + const gatewayOptions = { + ...baseGatewayOptions, + ...(context.onLog ? { onLog: context.onLog } : {}), + }; const catalog = await loadQueues(gateway, context); const deps: PageDependencies = { gateway, cursors: options.cursors, paths, now, gatewayOptions, catalog }; if (route.kind === "queues") { @@ -152,13 +160,14 @@ export function createSubmitQueueWeb(options: SubmitQueueWebOptions): SubmitQueu return notFound; } const requestId = request.requestId ?? newRequestId(); - const requestLogger = logger.child({ requestId }); + const onLog = createLogCallback(request.onLog, { requestId, path: request.path }); if (options.authorize && !(await options.authorize(request.principal, route))) { - requestLogger.info({ path: request.path }, "Web page request was not authorized"); + onLog("info", "Web page request was not authorized", {}); return { kind: "forbidden" }; } const context: SubmitQueueRequestContext = { requestId, + onLog, ...(request.principal === undefined ? {} : { principal: request.principal }), ...(request.signal ? { signal: request.signal } : {}), }; @@ -173,7 +182,7 @@ export function createSubmitQueueWeb(options: SubmitQueueWebOptions): SubmitQueu operation.end("exception"); span.recordException(cause instanceof Error ? cause : String(cause)); span.setStatus({ code: SpanStatusCode.ERROR }); - requestLogger.error({ path: request.path, err: cause }, "Web page load failed"); + onLog("error", "Web page load failed", { error: cause }); throw cause; } finally { span.end(); diff --git a/web/submitqueue/package.json b/web/submitqueue/package.json index bb170597c..9c40f6d60 100644 --- a/web/submitqueue/package.json +++ b/web/submitqueue/package.json @@ -37,7 +37,6 @@ }, "peerDependencies": { "@opentelemetry/api": ">=1.9 <2", - "pino": ">=10 <11", "react": ">=18 <20" }, "devDependencies": { @@ -49,7 +48,6 @@ "@types/react": "^19.1.0", "@types/react-dom": "^19.1.0", "jsdom": "^26.1.0", - "pino": "^10.4.0", "react": "^19.1.0", "react-dom": "^19.1.0", "typescript": "^5.8.3", diff --git a/web/test/package/BUILD.bazel b/web/test/package/BUILD.bazel index f8b91f3f3..5ad2fbcda 100644 --- a/web/test/package/BUILD.bazel +++ b/web/test/package/BUILD.bazel @@ -32,7 +32,6 @@ ts_project( "//web:node_modules/@bufbuild/protobuf", "//web:node_modules/@connectrpc/connect", "//web:node_modules/@opentelemetry/api", - "//web:node_modules/pino", "//web:node_modules/@types/node", "//web:node_modules/react", "//web:node_modules/react-dom", @@ -58,7 +57,6 @@ js_test( "//web:node_modules/@bufbuild/protobuf", "//web:node_modules/@connectrpc/connect", "//web:node_modules/@opentelemetry/api", - "//web:node_modules/pino", "//web:node_modules/react", "//web:node_modules/react-dom", ], diff --git a/web/test/package/consumer.ts b/web/test/package/consumer.ts index 3b6119f39..99d193ccb 100644 --- a/web/test/package/consumer.ts +++ b/web/test/package/consumer.ts @@ -8,7 +8,10 @@ const gateway: SubmitQueueGateway = createFakeGatewayReader(); const web = createSubmitQueueWeb({ gateway, cursors: newHmacCursorCodec("consumer-owned-secret") }); export async function render() { - const result = await web.handle({ path: "/demo-queue", search: {} }); + const result = await web.handle({ + path: "/demo-queue", search: {}, + onLog: (level, message, metadata) => { console[level](message, metadata); }, + }); if (result.kind !== "render") { return null; } diff --git a/web/test/package/pack_contents_test.py b/web/test/package/pack_contents_test.py index cbdac2d8a..48bb09232 100644 --- a/web/test/package/pack_contents_test.py +++ b/web/test/package/pack_contents_test.py @@ -8,7 +8,7 @@ # The module reads the gateway through a structural contract; the transport, # generated protos, and web framework belong to the host. -_FORBIDDEN_IMPORTS = ("@submitqueue/api", "@submitqueue/web-submitqueue", "@connectrpc/", "@bufbuild/", "next") +_FORBIDDEN_IMPORTS = ("@submitqueue/api", "@submitqueue/web-submitqueue", "@connectrpc/", "@bufbuild/", "next", "pino", "fusion-core", "fusion-tokens") # Modules the client-safe root entry must never reach, directly or transitively. _CLIENT_FORBIDDEN_MODULES = ("package/dist/controller/", "package/dist/module.js", "package/dist/server.js") @@ -81,7 +81,7 @@ def main() -> int: for group in ("peerDependencies", "dependencies", "optionalDependencies") for name in package.get(group, {}) ): - print("The core module must not require framework or transport dependencies.", file=sys.stderr) + print("The core module must not require framework, transport, or logging dependencies.", file=sys.stderr) return 1 stylesheet = package.get("exports", {}).get("./styles.css") if stylesheet != "./view/styles.css" or stylesheet not in package.get("sideEffects", []): diff --git a/web/test/package/react18/BUILD.bazel b/web/test/package/react18/BUILD.bazel index ce3f5d682..c0a3e920d 100644 --- a/web/test/package/react18/BUILD.bazel +++ b/web/test/package/react18/BUILD.bazel @@ -28,7 +28,6 @@ js_test( "//web:node_modules/@bufbuild/protobuf", "//web:node_modules/@connectrpc/connect", "//web:node_modules/@opentelemetry/api", - "//web:node_modules/pino", ], entry_point = "react18-runtime.mjs", ) diff --git a/web/tool/library.bzl b/web/tool/library.bzl index 0a3c5c265..4e876f5bd 100644 --- a/web/tool/library.bzl +++ b/web/tool/library.bzl @@ -64,7 +64,6 @@ def web_library(package, vitest, eslint, deps, test_deps = [], assets = []): # jest-dom resolves its vitest peer from the workspace root. "//web:node_modules/vitest", "//web:node_modules/@opentelemetry/api", - "//web:node_modules/pino", ] + deps, ) eslint.eslint_test(