From 6cb8231a9fbd28ee49887f8088f7455e42cf05af Mon Sep 17 00:00:00 2001 From: npeter83 Date: Sat, 19 Sep 2026 05:03:31 +0200 Subject: [PATCH] fix(logs): the browser's copy of a polled read is quiet too The server now logs polled reads at DEBUG, and the browser's copy of each request line promises the server's level: at INFO the unread-count polls filled My log within minutes and, at Detailed, the shipped log. The server marks a line it logged at DEBUG with X-Log-Quiet, so the polled-route list stays in one place. --- backend/app/logs.py | 4 ++++ backend/tests/test_logs.py | 7 +++++-- frontend/src/lib/api/core.ts | 3 ++- frontend/src/lib/http.test.ts | 15 ++++++++++++++- frontend/src/lib/http.ts | 21 +++++++++++++++------ 5 files changed, 40 insertions(+), 10 deletions(-) diff --git a/backend/app/logs.py b/backend/app/logs.py index 2dbb9979..565030c8 100644 --- a/backend/app/logs.py +++ b/backend/app/logs.py @@ -738,6 +738,10 @@ async def log_requests(request, call_next): extra={**event("http.request", **attrs), **_request_owner(request, level)}, ) response.headers["X-Request-Id"] = rid + # The browser logs its own copy of this line (frontend lib/http.ts) and must pick the same level: + # it learns "this one is quiet" here instead of keeping a second copy of the polled-route list. + if level == logging.DEBUG: + response.headers["X-Log-Quiet"] = "1" # The template, so the browser's copy of this line groups the same way (frontend lib/http.ts). # Only a MATCHED route's: a template never carries a path parameter's value (a share token stays # `{token}`), while the raw-path fallback of an unmatched request could — the browser then diff --git a/backend/tests/test_logs.py b/backend/tests/test_logs.py index ece53423..86363f67 100644 --- a/backend/tests/test_logs.py +++ b/backend/tests/test_logs.py @@ -337,10 +337,13 @@ def test_a_polled_read_is_debug_a_write_to_the_same_route_is_not(sink): http = logging.getLogger("siftlode.http") http.setLevel(logs.TRACE) client = _client() - client.get("/api/messages/unread_count") + r = client.get("/api/messages/unread_count") assert sink.objects()[-1]["level"] == "DEBUG" - client.post("/api/messages/unread_count") + # ...and says so, for the browser's copy of the line (frontend lib/http.ts). + assert r.headers["X-Log-Quiet"] == "1" + r = client.post("/api/messages/unread_count") assert sink.objects()[-1]["level"] == "INFO" + assert "X-Log-Quiet" not in r.headers client.get("/api/videos/abc") assert sink.objects()[-1]["level"] == "INFO" diff --git a/frontend/src/lib/api/core.ts b/frontend/src/lib/api/core.ts index cef102b0..3593f182 100644 --- a/frontend/src/lib/api/core.ts +++ b/frontend/src/lib/api/core.ts @@ -7,7 +7,7 @@ import i18n from "../../i18n"; import { formatBytes } from "../format"; import { reportError } from "../errorDialog"; import { activeAccountId, pinActiveAccount } from "../activeAccount"; -import { logRequest, REQUEST_ID_HEADER, ROUTE_HEADER, send } from "../http"; +import { logRequest, QUIET_HEADER, REQUEST_ID_HEADER, ROUTE_HEADER, send } from "../http"; import { newRequestId } from "../log"; /** The active UI language, as a bare code the server understands ("en"/"hu" — never "en-GB"). @@ -374,6 +374,7 @@ export function uploadReq( status: xhr.status, // Test doubles may not implement it; a real XHR always does. route: xhr.getResponseHeader?.(ROUTE_HEADER), + quiet: xhr.getResponseHeader?.(QUIET_HEADER) === "1", }); if (!RETRIABLE_GATEWAY.has(xhr.status)) markConnectivityRestored(); // as in `req` if (xhr.status >= 200 && xhr.status < 300) { diff --git a/frontend/src/lib/http.test.ts b/frontend/src/lib/http.test.ts index b8260f16..055e1c18 100644 --- a/frontend/src/lib/http.test.ts +++ b/frontend/src/lib/http.test.ts @@ -1,9 +1,10 @@ import { afterEach, describe, expect, it, vi } from "vitest"; import { pathTemplate, send } from "./http"; -import { clear, events } from "./log"; +import { clear, events, setLevel } from "./log"; afterEach(() => { + setLevel("INFO"); clear(); vi.unstubAllGlobals(); }); @@ -41,6 +42,18 @@ describe("send", () => { ]); }); + // The server logs the reads the app polls at DEBUG and says so (`X-Log-Quiet`); at INFO the + // browser's copies filled My log with unread-count polls within minutes (prod UAT 2026-09-19). + it("logs a read the server called quiet at DEBUG, so the base level keeps it out", async () => { + vi.stubGlobal("fetch", async () => answer(200, { "X-Log-Quiet": "1" })); + await send("/api/messages/unread_count"); + expect(events()).toEqual([]); + + setLevel("DEBUG"); + await send("/api/messages/unread_count"); + expect(events().map((e) => e.level)).toEqual(["DEBUG"]); + }); + it("logs a network failure without the concrete path, and still rejects", async () => { vi.stubGlobal("fetch", async () => { throw new TypeError("Failed to fetch"); diff --git a/frontend/src/lib/http.ts b/frontend/src/lib/http.ts index ec15f0ea..651b1024 100644 --- a/frontend/src/lib/http.ts +++ b/frontend/src/lib/http.ts @@ -12,6 +12,9 @@ import { log, newRequestId, type Level } from "./log"; * Grouping by it is what makes a client line comparable, and it is safe by construction: a token in * the path (`/api/public/watch/{token}`) arrives already replaced by its parameter name. */ export const ROUTE_HEADER = "X-Route"; +/** Set when the server logged this request at DEBUG (a polled read, the log console's own reads): the + * browser's copy of the line goes to DEBUG too, from the server's one list (`logs._POLLED_ROUTES`). */ +export const QUIET_HEADER = "X-Log-Quiet"; export const REQUEST_ID_HEADER = "X-Request-Id"; // A static path word: kept. Anything else (an id, a channel id, a share token) becomes `{}`. @@ -29,9 +32,9 @@ export function pathTemplate(url: string): string { } /** Level of a request line — the server's own rule (`logs.log_requests`), so both sides agree on - * what a 404 is. */ -function statusLevel(status: number): Level { - return status >= 500 ? "ERROR" : status >= 400 ? "WARNING" : "INFO"; + * what a 404 is, and on which successes are too routine for INFO (`quiet`, the server's say). */ +function statusLevel(status: number, quiet: boolean): Level { + return status >= 500 ? "ERROR" : status >= 400 ? "WARNING" : quiet ? "DEBUG" : "INFO"; } /** Record one request's outcome. `route` is the server's template when it sent one. */ @@ -40,7 +43,9 @@ export function logRequest( method: string, url: string, started: number, - outcome: { status: number; route?: string | null } | { failed: "network" | "aborted" }, + outcome: + | { status: number; route?: string | null; quiet?: boolean } + | { failed: "network" | "aborted" }, extra: Record = {}, ): void { const duration_ms = Math.round((performance.now() - started) * 10) / 10; @@ -56,7 +61,7 @@ export function logRequest( } const path = outcome.route || pathTemplate(url); log.request( - statusLevel(outcome.status), + statusLevel(outcome.status, outcome.quiet === true), `${method} ${path} ${outcome.status}`, { method, path, status: outcome.status, duration_ms, ...extra }, requestId, @@ -92,7 +97,11 @@ export async function send( method, url, started, - { status: r.status, route: headerOf(r, ROUTE_HEADER) }, + { + status: r.status, + route: headerOf(r, ROUTE_HEADER), + quiet: headerOf(r, QUIET_HEADER) === "1", + }, extra, ); return r;