From 12f3dd5b0796f03cafd3e5d12c739c3c5f3251d9 Mon Sep 17 00:00:00 2001 From: clawbot <35+clawbot@noreply.example.org> Date: Wed, 14 Oct 2026 14:13:03 +0200 Subject: [PATCH] Debug log adds each line instead of drawing the whole panel (closes #131) With the debug log open, every line written drew the panel again with up to 1000 lines, and a check that ends while the page draws is timed only when the drawing is done, so latencies measured with the panel open read too high. Each line is now appended to the open panel and its first line dropped once it holds more than maxLogEntries; the whole panel is drawn only when it is opened. Scrolling to the newest line reads the panel's height, which lays out all its lines, so it runs once a frame, with at most one frame request waiting. Model: opus-5-5 --- TODO.md | 9 +++++++ test/unit/main.test.js | 54 +++++++++++++++++++++++++++++++++------ web/src/main.js | 57 ++++++++++++++++++++++++++++++------------ 3 files changed, 96 insertions(+), 24 deletions(-) diff --git a/TODO.md b/TODO.md index de845ba..d119197 100644 --- a/TODO.md +++ b/TODO.md @@ -21,6 +21,15 @@ Run `make frontend-viewport-test` in CI as its own step; it is not part of # Completed Steps +- 2026-10-14: opening the debug log no longer raises the measured latencies + ([#131](https://git.eeqj.de/sneak/netwatch/issues/131)). With the panel open, + each line written drew the panel again with every line before it, up to 1000, + and a check that ends while the page draws is timed only when the drawing is + done. Each line is now added at the end of the open panel, its first line is + dropped once it holds more than 1000, and it scrolls to its newest line once a + frame rather than once a line; the whole panel is drawn only when it is + opened. A unit test writes more lines than the panel keeps and checks that the + lines already shown are left as they are - 2026-10-14: unset, the backend's own `TRUSTED_PROXIES` trusts `10.0.0.0/8`, `172.16.0.0/12` and `192.168.0.0/16`, and no longer loopback; a list replaces that; set and empty, it trusts no proxy, where it used to get the default, as diff --git a/test/unit/main.test.js b/test/unit/main.test.js index 9b8ada8..dcdb1a6 100644 --- a/test/unit/main.test.js +++ b/test/unit/main.test.js @@ -13,20 +13,22 @@ import { humanDuration, latencyClass, latencyHex, + log, measureLatency, Reporter, tick, } from "../../web/src/main.js"; // There is no page here, so the tests stand in for it. The debug log looks -// for its panel by id and finds none. Each element of a host's row that -// tick or greyOutUI draws into is a plain object, made the first time a -// test looks it up and kept in elements under its selector until the next -// test starts. As on a page, writing its text replaces its markup; the -// status dot greyOutUI looks for in it is not there. Drawing a sparkline -// does nothing; it looks for the pixel ratio on window and finds none. In -// each test, console.error and console.info print nothing and keep what -// they are given. +// for its panel by id and finds none, an element the page creates is a +// plain object, and no frame the page asks for ever comes. Each element of +// a host's row that tick or greyOutUI draws into is a plain object, made +// the first time a test looks it up and kept in elements under its +// selector until the next test starts. As on a page, writing its text +// replaces its markup; the status dot greyOutUI looks for in it is not +// there. Drawing a sparkline does nothing; it looks for the pixel ratio on +// window and finds none. In each test, console.error and console.info +// print nothing and keep what they are given. const doNothing = () => {}; let elements; beforeEach((t) => { @@ -46,8 +48,11 @@ const canvasContext = { arc: doNothing, }; globalThis.window = {}; +globalThis.requestAnimationFrame = doNothing; +globalThis.cancelAnimationFrame = doNothing; globalThis.document = { getElementById: () => null, + createElement: () => ({}), querySelector: (selector) => (elements[selector] ??= { getContext: () => canvasContext, @@ -471,6 +476,39 @@ test("of the checks interval changes cleared before they were reported, the next assert.equal(sent.at(-1).t, 120000); }); +// panel stands in for the open debug log panel, and for the element in it +// that holds its lines, whichever the page looks up by id; the lines are +// kept in order in lines. Drawing the whole panel, as opening it does, +// replaces every line with a new one. +test("with the debug log open, writing more lines than it keeps adds each to the panel and leaves the lines already shown as they are", (t) => { + const lines = []; + const panel = { + classList: { contains: () => false }, + children: lines, + get firstElementChild() { + return lines[0]; + }, + append: (line) => lines.push(line), + removeChild: (line) => lines.splice(lines.indexOf(line), 1), + replaceChildren: (...newLines) => + lines.splice(0, lines.length, ...newLines), + }; + t.mock.method(globalThis.document, "getElementById", () => panel); + const kept = CONFIG.maxLogEntries; + + for (let i = 1; i <= kept; i++) log.info(`line ${i}`); + const shown = [...lines]; + for (let i = kept + 1; i <= kept + 5; i++) log.info(`line ${i}`); + + assert.deepEqual( + lines.map((line) => line.textContent.match(/line \d+$/)?.[0]), + Array.from({ length: kept }, (_, i) => `line ${i + 6}`), + ); + // The first five lines shown were dropped, and the rest are the same + // lines, not drawn again. + shown.slice(5).forEach((line, i) => assert.equal(lines[i], line)); +}); + // The page shows < > " & and ' in a row's markup as // < > " & and '. test(`a target whose name and URL hold < > " & and ' shows those characters in its row`, () => { diff --git a/web/src/main.js b/web/src/main.js index 077c7e1..065dc26 100644 --- a/web/src/main.js +++ b/web/src/main.js @@ -144,13 +144,15 @@ const WAN_HOSTS = [ const debugLog = []; -const log = (() => { +export const log = (() => { function append(level, message) { - debugLog.push({ timestamp: new Date(), level, message }); + const entry = { timestamp: new Date(), level, message }; + debugLog.push(entry); if (debugLog.length > CONFIG.maxLogEntries) debugLog.splice(0, debugLog.length - CONFIG.maxLogEntries); const panel = document.getElementById("debug-panel"); - if (panel && !panel.classList.contains("hidden")) renderDebugLog(); + if (panel && !panel.classList.contains("hidden")) + appendDebugLogLine(entry); } return { error: (msg) => append("error", msg), @@ -1107,9 +1109,8 @@ function updateHealthBox(state) { // --- Debug Log Renderer ------------------------------------------------------ -function renderDebugLog() { - const el = document.getElementById("debug-log"); - if (!el) return; +// One line of the debug log panel, its message set as text. +function debugLogLine(entry) { const levelColors = { error: "text-red-400", warning: "text-orange-400", @@ -1117,19 +1118,43 @@ function renderDebugLog() { info: "text-gray-300", debug: "text-gray-500", }; - el.replaceChildren( - ...debugLog.map((entry) => { - const ts = formatUTCTimestamp(entry.timestamp); - const lvl = entry.level.toUpperCase().padEnd(7); - const line = document.createElement("div"); - line.className = levelColors[entry.level] || "text-gray-400"; - line.textContent = `${ts} ${lvl} ${entry.message}`; - return line; - }), - ); + const ts = formatUTCTimestamp(entry.timestamp); + const lvl = entry.level.toUpperCase().padEnd(7); + const line = document.createElement("div"); + line.className = levelColors[entry.level] || "text-gray-400"; + line.textContent = `${ts} ${lvl} ${entry.message}`; + return line; +} + +// Draws every line of the debug log into the panel, when it is opened. +function renderDebugLog() { + const el = document.getElementById("debug-log"); + if (!el) return; + el.replaceChildren(...debugLog.map((entry) => debugLogLine(entry))); el.scrollTop = el.scrollHeight; } +// The request that scrolls the open panel to its newest line in the next +// frame. One waits at most, also in a hidden tab, where frames do not run. +let debugLogScrollFrame = 0; + +// Adds entry to the open panel as its last line, and drops the first line +// once the panel holds more than maxLogEntries. A check that ends while the +// page is busy is timed only when the page is done, so the lines already +// shown are left as they are, and the panel is scrolled once a frame +// rather than once a line: scrolling it lays out all of its lines again. +function appendDebugLogLine(entry) { + const el = document.getElementById("debug-log"); + if (!el) return; + el.append(debugLogLine(entry)); + if (el.children.length > CONFIG.maxLogEntries) + el.removeChild(el.firstElementChild); + cancelAnimationFrame(debugLogScrollFrame); + debugLogScrollFrame = requestAnimationFrame(() => { + el.scrollTop = el.scrollHeight; + }); +} + // --- Sorting ----------------------------------------------------------------- // Sort WAN hosts: pinned hosts first (alphabetically), then unpinned hosts