From d7c439b7663e80ef2b9423421ae18008f46ebf52 Mon Sep 17 00:00:00 2001 From: kittors Date: Sat, 8 Aug 2026 10:33:31 +0800 Subject: [PATCH] fix(online-update): stop polling update progress without permission An idle panel tab issued ~33 requests a minute, forever, against endpoints it often had no right to call. Measured on a live instance: GET /update/progress every ~2s and an /update/events reconnect every ~3s, from every open tab, on a deployment with no updater sidecar where each of those fails. The backend audited each refusal, which is how the governance page ended up holding 28,435 rows of one operator being told no. Three causes, three fixes: - The provider subscribed every authenticated operator. It is now gated on system.status.read, the permission the update endpoints actually require and the one the system route already declares. - The transport treated "no run in flight" the same as "mid-update", so the aggressive cadence the container restart needs ran around the clock. Cadence now follows what is happening: unchanged while a run is in flight (2s polls, sub-second reconnects), 30s polls backing off to 5m and 3-30s reconnects when idle. - A 403 is not transient. The transport now stops instead of retrying, and resets when the last subscriber leaves so a new session is not stuck with it. The audit page also rendered "denied" and "failed" as the same red badge, hiding the distinction that matters most there: refused is not the same as errored. Co-Authored-By: Claude Opus 5 --- apps/admin-panel/src/app/AppRouter.tsx | 11 +- .../progress/progressStream.test.ts | 49 ++++++- .../online-update/progress/progressStream.ts | 138 ++++++++++++++++-- packages/i18n/src/locales/en.json | 1 + packages/i18n/src/locales/ru.json | 1 + packages/i18n/src/locales/zh-CN.json | 1 + pages/audit-logs/AuditLogsPage.tsx | 49 +++++-- .../__tests__/AuditLogsPage.test.tsx | 36 +++++ 8 files changed, 254 insertions(+), 32 deletions(-) diff --git a/apps/admin-panel/src/app/AppRouter.tsx b/apps/admin-panel/src/app/AppRouter.tsx index c1d2de05..554ee98d 100644 --- a/apps/admin-panel/src/app/AppRouter.tsx +++ b/apps/admin-panel/src/app/AppRouter.tsx @@ -136,7 +136,7 @@ function StaleRoutePage() { /** Must render Routes itself so embed s are direct children of . */ function AuthenticatedRoutes() { - const { state } = useAuth(); + const { state, can } = useAuth(); const routes = pageRoutes; const publicRoutes = routes.filter((r) => !r.auth); const authStandaloneRoutes = routes.filter((r) => r.auth && r.layout === "standalone"); @@ -149,8 +149,15 @@ function AuthenticatedRoutes() { [state.principal?.menus], ); + // Online update is gated on the same permission its endpoints require + // (system.status.read, per the backend's route permission table). Subscribing + // every authenticated operator meant tenant admins polled an endpoint the server + // refuses, forever: on a live instance that was ~28k refusals in the audit log in + // 18 hours, from a feature those operators cannot use. return ( - + }> diff --git a/features/online-update/progress/progressStream.test.ts b/features/online-update/progress/progressStream.test.ts index b356b889..472e2cfa 100644 --- a/features/online-update/progress/progressStream.test.ts +++ b/features/online-update/progress/progressStream.test.ts @@ -59,10 +59,12 @@ describe("update progress transport", () => { * The regression that made online update look broken: applying an update recreates * the container serving this stream, so it always drops. The old backoff started * at 5s and doubled to 60s, so the modal froze for the whole restart. Reconnects - * must be fast enough to be invisible. + * must be fast enough to be invisible — while a run is in flight, which is what + * the poll below establishes before the reconnects are counted. */ - test("reconnects quickly after the stream drops", async () => { + test("reconnects quickly after the stream drops during a run", async () => { mocks.events.mockRejectedValue(new Error("container restarting")); + mocks.progress.mockResolvedValue(running()); const unsubscribe = subscribeUpdateProgress(() => {}); await until(() => mocks.events.mock.calls.length >= 3); @@ -70,6 +72,49 @@ describe("update progress transport", () => { unsubscribe(); }); + /** + * The other half of that trade. Panels sit open for hours with nothing being + * updated, and on a deployment without the updater sidecar every request fails; + * reconnecting three times a second for days is pure load, and each failed poll + * used to write an audit row. + */ + test("backs off instead of hammering while nothing is in flight", async () => { + mocks.events.mockRejectedValue(new Error("no updater")); + mocks.progress.mockRejectedValue(new Error("no updater")); + + const unsubscribe = subscribeUpdateProgress(() => {}); + // One connect attempt lands immediately; the idle backoff starts at 3s, so a + // second attempt inside a second would mean the aggressive cadence is still on. + await until(() => mocks.events.mock.calls.length >= 1); + await new Promise((resolve) => globalThis.setTimeout(resolve, 1000)); + expect(mocks.events.mock.calls.length).toBeLessThanOrEqual(2); + // The idle poll cadence is 30s, so the immediate poll must be the only one. + expect(mocks.progress.mock.calls.length).toBe(1); + + unsubscribe(); + }); + + /** + * A refusal is not a transient failure: the operator lacks the permission the + * update endpoints require, and retrying only fills the audit log. + */ + test("stops entirely once the server refuses the operator", async () => { + const forbidden = Object.assign(new Error("permission denied"), { status: 403 }); + mocks.events.mockRejectedValue(forbidden); + mocks.progress.mockRejectedValue(forbidden); + + const unsubscribe = subscribeUpdateProgress(() => {}); + await until(() => mocks.progress.mock.calls.length >= 1); + const callsAfterRefusal = mocks.events.mock.calls.length + mocks.progress.mock.calls.length; + + await new Promise((resolve) => globalThis.setTimeout(resolve, 500)); + expect(mocks.events.mock.calls.length + mocks.progress.mock.calls.length).toBe( + callsAfterRefusal, + ); + + unsubscribe(); + }); + /** A dropped stream is a normal part of an update, not a failure to surface. */ test("reports the link as reconnecting while the stream is unavailable", async () => { mocks.events.mockRejectedValue(new Error("container restarting")); diff --git a/features/online-update/progress/progressStream.ts b/features/online-update/progress/progressStream.ts index 9b75c1e9..55229619 100644 --- a/features/online-update/progress/progressStream.ts +++ b/features/online-update/progress/progressStream.ts @@ -2,6 +2,7 @@ import { updateApi, type UpdateProgressResponse, } from "@code-proxy/api-client/endpoints/update"; +import { isRunningProgress } from "../model/updateModel"; /** * Transport for update progress. @@ -23,17 +24,54 @@ import { * if the stream never comes back (a buffering proxy, for instance). * 3. Resume from the last event id so the reconnect delivers what was missed * instead of dropping the client into a hole. + * + * All of that is right *during* an update and wrong the rest of the time, which is + * almost always. Panels are left open for hours with nothing being updated, and on + * a deployment without the updater sidecar every request fails: measured on a live + * instance, one idle tab issued ~33 requests a minute forever — a 5s-timeout 502 on + * every poll, plus a stream that answered 204 and was immediately reconnected. Each + * failed poll also wrote an audit row, which is how the governance page ended up + * holding 33k rows of update polling. + * + * So the cadence follows what is actually happening: fast while a run is in flight + * (the case the aggressive reconnect exists for), slow and backing off when idle. */ -/** Reconnect delays. Deliberately aggressive: the server being gone is expected. */ +/** + * Reconnect delays while a run is in flight. Deliberately aggressive: the server + * being gone is the expected path through an update. + */ const RECONNECT_BASE_MS = 300; const RECONNECT_FACTOR = 1.6; const RECONNECT_MAX_MS = 3000; const RECONNECT_JITTER = 0.25; -/** Poll cadence while the stream is unavailable. */ +/** + * Reconnect delays when no run is in flight. A stream that is not delivering while + * nothing is happening is not an incident, and reconnecting at three per second + * only costs the server. + */ +const IDLE_RECONNECT_BASE_MS = 3000; +const IDLE_RECONNECT_MAX_MS = 30_000; + +/** Poll cadence while a run is in flight and the stream is not delivering. */ const POLL_INTERVAL_MS = 2000; +/** + * Poll cadence when nothing is in flight, backing off while it keeps failing. The + * ceiling still catches an update started elsewhere within half a minute or so of + * a healthy endpoint answering. + */ +const IDLE_POLL_INTERVAL_MS = 30_000; +const IDLE_POLL_MAX_MS = 300_000; + +/** + * How long an explicit refresh keeps the fast cadence. It covers the window + * between "apply accepted" and the first progress event, during which there is + * nothing in `latest` to prove a run is in flight. + */ +const ACTIVE_HINT_MS = 5 * 60_000; + /** * How long the transport may be out of contact before it stops claiming an update * is merely restarting. This replaces the old fixed 180s run timeout, which failed @@ -78,9 +116,31 @@ let latest: UpdateProgressResponse | null = null; let lastEventId: number | null = null; let link: UpdateLinkState = "reconnecting"; let lastContactAt: number | null = null; +let activeHintUntil = 0; +let pollFailures = 0; +/** + * Set when the server refuses the operator outright. Retrying cannot change a + * permission decision, and it was those retries — one refusal every two seconds + * from every open tab — that buried the audit log. + */ +let refused = false; const now = () => Date.now(); +/** + * Whether an update is believed to be in flight. Everything that trades server + * load for latency keys off this. + */ +const isActive = () => isRunningProgress(latest) || now() < activeHintUntil; + +/** Reads a status off an unknown rejection without depending on the error class. */ +const statusOf = (error: unknown): number => + typeof (error as { status?: unknown } | null)?.status === "number" + ? (error as { status: number }).status + : 0; + +const isRefusal = (error: unknown) => statusOf(error) === 403; + const snapshot = (): UpdateProgressSnapshot => { const staleForMs = lastContactAt === null ? null : now() - lastContactAt; return { @@ -119,13 +179,26 @@ const accept = (progress: UpdateProgressResponse, source: UpdateLinkState) => { }; const reconnectDelay = (attempt: number) => { - const base = Math.min(RECONNECT_MAX_MS, RECONNECT_BASE_MS * RECONNECT_FACTOR ** Math.max(0, attempt)); + const [start, ceiling] = isActive() + ? [RECONNECT_BASE_MS, RECONNECT_MAX_MS] + : [IDLE_RECONNECT_BASE_MS, IDLE_RECONNECT_MAX_MS]; + const base = Math.min(ceiling, start * RECONNECT_FACTOR ** Math.max(0, attempt)); // Jitter keeps several open tabs from retrying in lockstep against a container // that is still coming up. const jitter = base * RECONNECT_JITTER * (Math.random() * 2 - 1); return Math.max(0, Math.round(base + jitter)); }; +/** + * Delay before the next poll. While a run is in flight this is the old fixed + * cadence; otherwise it starts slow and doubles for as long as the endpoint keeps + * failing, which is the shape of a deployment with no updater sidecar. + */ +const pollDelay = () => { + if (isActive()) return POLL_INTERVAL_MS; + return Math.min(IDLE_POLL_MAX_MS, IDLE_POLL_INTERVAL_MS * 2 ** Math.min(pollFailures, 8)); +}; + const sleep = (ms: number, signal: AbortSignal) => new Promise((resolve) => { if (signal.aborted) { @@ -148,9 +221,16 @@ const sleep = (ms: number, signal: AbortSignal) => const pollOnce = async (signal: AbortSignal) => { try { const progress = await updateApi.progress({ signal }); + pollFailures = 0; if (!signal.aborted) accept(progress, link === "live" ? "live" : "polling"); - } catch { - if (!signal.aborted && link !== "live") { + } catch (error: unknown) { + if (signal.aborted) return; + if (isRefusal(error)) { + stopTransport(); + return; + } + pollFailures += 1; + if (link !== "live") { link = "reconnecting"; emit(); } @@ -162,9 +242,9 @@ const startPolling = (signal: AbortSignal) => { if (signal.aborted) return; // Polling only covers the gap; while the stream is healthy it would be noise. if (link !== "live") await pollOnce(signal); - if (!signal.aborted) pollTimer = globalThis.setTimeout(tick, POLL_INTERVAL_MS); + if (!signal.aborted && !refused) pollTimer = globalThis.setTimeout(tick, pollDelay()); }; - pollTimer = globalThis.setTimeout(tick, POLL_INTERVAL_MS); + pollTimer = globalThis.setTimeout(tick, pollDelay()); }; const stopPolling = () => { @@ -174,8 +254,21 @@ const stopPolling = () => { } }; +/** + * Stops the transport without dropping subscribers, so a refused operator keeps + * whatever state was already rendered instead of watching it reset. + */ +const stopTransport = () => { + refused = true; + generation += 1; + stopPolling(); + controller?.abort(); + controller = null; + running = null; +}; + const ensureStream = () => { - if (running || listeners.size === 0) return; + if (running || listeners.size === 0 || refused) return; const abort = new AbortController(); const myGeneration = generation; @@ -205,8 +298,13 @@ const ensureStream = () => { params: lastEventId === null ? undefined : { last_event_id: String(lastEventId) }, }, ); - } catch { - // Expected whenever the application container is recreated. + } catch (error: unknown) { + // Expected whenever the application container is recreated — unless the + // server refused the operator, which no amount of reconnecting fixes. + if (isRefusal(error)) { + stopTransport(); + break; + } } if (signal.aborted || listeners.size === 0 || generation !== myGeneration) break; @@ -235,6 +333,11 @@ const teardown = () => { lastEventId = null; lastContactAt = null; link = "reconnecting"; + activeHintUntil = 0; + pollFailures = 0; + // Cleared with the rest of the state: the next subscriber may be a different + // session, and a sign-in with the permission must not inherit the refusal. + refused = false; }; /** Subscribes to update progress. Returns an unsubscribe function. */ @@ -250,9 +353,20 @@ export const subscribeUpdateProgress = (listener: Listener) => { }; }; -/** Forces an immediate refresh, used right after triggering an update. */ +/** + * Forces an immediate refresh, used right after triggering an update. It also + * arms the fast cadence: the run has been accepted but nothing has reported it + * yet, so `latest` cannot prove anything is in flight. + */ export const refreshUpdateProgress = () => { - if (controller) void pollOnce(controller.signal); + activeHintUntil = now() + ACTIVE_HINT_MS; + if (controller) { + void pollOnce(controller.signal); + // The pending timer was scheduled at the idle cadence; reschedule so the next + // poll lands two seconds from now rather than up to five minutes away. + stopPolling(); + startPolling(controller.signal); + } }; /** Test seam: resets module state between cases. */ diff --git a/packages/i18n/src/locales/en.json b/packages/i18n/src/locales/en.json index d757ad7e..3174d2ea 100644 --- a/packages/i18n/src/locales/en.json +++ b/packages/i18n/src/locales/en.json @@ -4954,6 +4954,7 @@ "what_happened": "What happened", "result_success": "Success", "result_failed": "Failed", + "result_denied": "Denied", "request_id": "Request ID", "call_chain": "Call chain", "project_method": "Project method", diff --git a/packages/i18n/src/locales/ru.json b/packages/i18n/src/locales/ru.json index a4247f75..d4ba8ef9 100644 --- a/packages/i18n/src/locales/ru.json +++ b/packages/i18n/src/locales/ru.json @@ -2745,6 +2745,7 @@ "what_happened": "Что сделано", "result_success": "Успех", "result_failed": "Ошибка", + "result_denied": "Отказано", "request_id": "ID запроса", "call_chain": "Цепочка вызовов", "project_method": "Метод проекта", diff --git a/packages/i18n/src/locales/zh-CN.json b/packages/i18n/src/locales/zh-CN.json index 0c72a909..0f80bbc9 100644 --- a/packages/i18n/src/locales/zh-CN.json +++ b/packages/i18n/src/locales/zh-CN.json @@ -4828,6 +4828,7 @@ "what_happened": "操作内容", "result_success": "成功", "result_failed": "失败", + "result_denied": "已拒绝", "request_id": "请求 ID", "call_chain": "调用链路", "project_method": "项目方法", diff --git a/pages/audit-logs/AuditLogsPage.tsx b/pages/audit-logs/AuditLogsPage.tsx index f51cb322..141f2174 100644 --- a/pages/audit-logs/AuditLogsPage.tsx +++ b/pages/audit-logs/AuditLogsPage.tsx @@ -22,8 +22,29 @@ import { PermissionGate } from "@app/providers/PermissionGate"; const DEFAULT_PAGE_SIZE = 50; const PAGE_SIZE_OPTIONS = [20, 50, 100]; -function isSuccessResult(result: string): boolean { - return result === "success"; +/** + * The backend records three outcomes, and rendering two of them identically hid + * the distinction that matters most on this page: "the server refused this" and + * "the server tried and errored" are different events with different follow-ups. + */ +const RESULT_BADGE: Record = { + success: { + labelKey: "identity_admin.result_success", + className: + "bg-emerald-50 text-emerald-600 dark:bg-emerald-500/15 dark:text-emerald-300", + }, + denied: { + labelKey: "identity_admin.result_denied", + className: "bg-amber-50 text-amber-700 dark:bg-amber-500/15 dark:text-amber-300", + }, + failed: { + labelKey: "identity_admin.result_failed", + className: "bg-rose-50 text-rose-600 dark:bg-rose-500/15 dark:text-rose-300", + }, +}; + +function resultBadge(result: string) { + return RESULT_BADGE[result] ?? RESULT_BADGE.failed; } function formatActor(item: AuditLogIdentity): string { @@ -216,16 +237,16 @@ export function AuditLogsPage() { width: COLUMN_WIDTH.badge, headerClassName: "text-center", cellClassName: "text-center", - render: (item) => - isSuccessResult(item.result) ? ( - - {t("identity_admin.result_success")} - - ) : ( - - {t("identity_admin.result_failed")} + render: (item) => { + const badge = resultBadge(item.result); + return ( + + {t(badge.labelKey)} - ), + ); + }, }, { key: "actions", @@ -345,11 +366,7 @@ export function AuditLogsPage() { /> { ).not.toBeInTheDocument(); }); + /** + * "Refused" and "errored" used to render as the same red badge, which is the + * distinction an audit reader most needs: one is somebody being denied access, + * the other is the server failing. + */ + test("distinguishes a refused result from a failed one", async () => { + auditLogs.mockResolvedValue({ + items: [ + { + id: 21, + tenant_id: "t-1", + tenant_name: "Acme", + tenant_slug: "acme", + actor_kind: "user_session", + actor_user_id: "u-1", + actor_username: "alice", + actor_display_name: "Alice", + action: "management.get", + resource_type: "update", + resource_id: "progress", + result: "denied", + request_id: "req-3", + created_at: "2026-08-08T09:51:15Z", + }, + ], + total: 1, + page: 1, + size: 50, + }); + + render(); + + expect(await screen.findByText("identity_admin.result_denied")).toBeInTheDocument(); + expect(screen.queryByText("identity_admin.result_failed")).not.toBeInTheDocument(); + }); + test("opens detail with call chain and project method", async () => { const user = userEvent.setup(); render();