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

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
+// for its panel by id and finds none, an element the page creates is a
-// tick or greyOutUI draws into is a plain object, made the first time a
+// plain object, and no frame the page asks for ever comes. Each element of
-// test looks it up and kept in elements under its selector until the next
+// a host's row that tick or greyOutUI draws into is a plain object, made
-// test starts. As on a page, writing its text replaces its markup; the
+// the first time a test looks it up and kept in elements under its
-// status dot greyOutUI looks for in it is not there. Drawing a sparkline
+// selector until the next test starts. As on a page, writing its text
-// does nothing; it looks for the pixel ratio on window and finds none. In
+// replaces its markup; the status dot greyOutUI looks for in it is not
-// each test, console.error and console.info print nothing and keep what
+// there. Drawing a sparkline does nothing; it looks for the pixel ratio on
-// they are given.
+// 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 &lt; &gt; &quot; &amp; and &#39; in a row's markup as
 // < > " & and '.
 test(`a target whose name and URL hold < > " & and ' shows those characters in its row`, () => {

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() {
+// One line of the debug log panel, its message set as text.
-    const el = document.getElementById("debug-log");
+function debugLogLine(entry) {
-    if (!el) return;
     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(
+    const ts = formatUTCTimestamp(entry.timestamp);
-        ...debugLog.map((entry) => {
+    const lvl = entry.level.toUpperCase().padEnd(7);
-            const ts = formatUTCTimestamp(entry.timestamp);
+    const line = document.createElement("div");
-            const lvl = entry.level.toUpperCase().padEnd(7);
+    line.className = levelColors[entry.level] || "text-gray-400";
-            const line = document.createElement("div");
+    line.textContent = `${ts} ${lvl} ${entry.message}`;
-            line.className = levelColors[entry.level] || "text-gray-400";
+    return line;
-            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