diff --git a/PHASE2-FINDINGS.md b/PHASE2-FINDINGS.md index 809a9b507..cdb340112 100644 --- a/PHASE2-FINDINGS.md +++ b/PHASE2-FINDINGS.md @@ -283,23 +283,60 @@ point where the update entered the tree. re-renders over 30,000 times. That is the churn behind the 650 MB peak: it is transient allocation, not retention. -Roughly 80% of those commits enter at the *same place*: an anonymous provider at depth 2 -whose props are `[value, children]` and whose value is `{appDir}` — Next.js's internal -`HeadManagerContext`. Its value is a fresh object literal on every App Router render, so -each one re-renders the entire application below it. The remainder enter around -`__next_metadata_boundary__` / ``, which points the same way. +> ### Correction: this was wrong, and it was the wrong thing to chase +> +> An earlier round of this work concluded that ~80% of commits entered at an anonymous depth-2 +> provider with props `[value, children]` and value `{appDir}` — Next's internal +> `HeadManagerContext` — and therefore that "the App Router root re-renders about once a second" +> was the dominant cost and the highest-value next step. +> +> **Both claims are false.** Measuring the same idle churn against boards of different sizes: +> +> | board | items | idle commits/min | +> | --- | --- | --- | +> | `hey` | 0 | **0.0** | +> | `footbol` | 3 | **0.0** | +> | `default` | 28 | **76.0** | +> +> A 3-item board commits **zero** times per minute. If the App Router re-rendered on a timer, +> every board would churn regardless of its contents. The churn is entirely widget-driven. +> +> The original attribution was an artefact: `measure-rerenders.mts` decides a fiber re-rendered +> from `fiber.actualDuration`, which **only a React profiling build populates**. On a production +> build every fiber fails that test and both attribution tables come back empty — and an empty +> table reads as "nothing here" rather than "this build cannot tell you". The tool now says which +> case it is instead of printing nothing. The depth-2 provider was whatever survived that filter +> in a profiling build, not the cause. -So the dominant cost is the **App Router root re-rendering about once a second**, not any -individual widget. No polling `router.refresh()` exists in application code, so the -trigger is inside Next's own router/metadata handling and is not fixed by anything in -this PR. That is the next thing to chase, and it is worth more than any further -component-level tuning: everything else is downstream of it. +Attribution that works on a production build uses DOM mutations instead — +`scripts/benchmarks/measure-widget-churn.mts`. Every re-render that changes anything observable +mutates the DOM, and the mutated node's nearest `[data-type="item"]` ancestor names the widget. +On the 28-item board, idle for 45 s: + +| widget | mutations | share | +| --- | --- | --- | +| **beszelSystemStats** | **470** | **64%** | +| beszelSystemTable | 77 | 11% | +| beszelSystemGrid | 52 | 7% | +| dockerContainers | 22 | 3% | +| immich-albumCarousel | 14 | 2% | +| downloads | 4 | 1% | +| (outside any widget) | 93 | 13% | + +**Three Beszel widgets account for 82% of all idle churn**, one of them for 64% on its own, at +10.4 mutations per second. + +The mechanism is in `packages/widgets/src/beszel/_shared/use-live-stats.ts`: the tRPC +subscription's `onData` called `setSystemStats((prev) => [...prev, record])` — one React state +update per record, each allocating a fresh 60-element array. Beszel pushes one record per second +*per system*, plus one per container, so a widget watching several systems drives a steady stream +of renders. Records are now accumulated outside React and flushed once a second, which is the +fastest a 60-second sliding-window chart can meaningfully show. Nothing is dropped. `useTimeAgo` was calling `setState` every second even when the rendered label was unchanged ("3 minutes ago" holds for a minute), so it now compares before setting. This -is a correctness fix — idle commits stayed within their 73–96 range afterwards, because -the app-root churn dominates and this hook is not what drives it. Recorded as *not* a -measured win. +is a correctness fix — idle commits did not move measurably, because the Beszel widgets +dominate and this hook is not what drives them. Recorded as *not* a measured win. ## What is actually hogging the memory diff --git a/scripts/benchmarks/measure-rerenders.mts b/scripts/benchmarks/measure-rerenders.mts index bfbb394e1..f607259c3 100644 --- a/scripts/benchmarks/measure-rerenders.mts +++ b/scripts/benchmarks/measure-rerenders.mts @@ -22,7 +22,19 @@ const browser = await chromium.launch(); const context = await browser.newContext({ viewport: { width: 1920, height: 1080 } }); await context.addInitScript(() => { - const state = { commits: 0, byComponent: new Map<string, number>(), roots: new Map<string, number>(), started: 0 }; + const state = { + commits: 0, + byComponent: new Map<string, number>(), + roots: new Map<string, number>(), + started: 0, + /** + * Whether any fiber carried `actualDuration`. React only populates it in a profiling + * build, so on a production build every fiber fails the re-render test and the + * attribution comes back empty — which reads as "nothing re-rendered" rather than + * "this build cannot tell you". Tracked so the report can say which it is. + */ + sawTimings: false, + }; (globalThis as unknown as Record<string, unknown>).__homarrRenderStats = state; const nameOf = (fiber: { type?: unknown; elementType?: unknown }) => { @@ -60,6 +72,7 @@ await context.addInitScript(() => { if (!fiber || seen.has(fiber) || depth > 2000) return; seen.add(fiber); const alternate = fiber.alternate as Record<string, unknown> | null; + if (fiber.actualDuration !== undefined) state.sawTimings = true; // A fiber re-rendered if it committed new work over a previous version. if (alternate && fiber.actualDuration !== undefined && (fiber.actualDuration as number) > 0) { const name = nameOf(fiber as never); @@ -122,15 +135,15 @@ await page.locator("css=button[type='submit']").click(); await page.waitForFunction(() => !window.location.pathname.includes("/auth/login"), undefined, { timeout: 60_000 }); await page.goto(`${baseUrl}/boards/${boardName}`, { waitUntil: "domcontentloaded" }); -await page.locator("[data-homarr-dev-benchmark-board]").waitFor({ state: "visible", timeout: 120_000 }); +// Attached, not visible: a board with zero items renders this container hidden, and the +// empty-board case is exactly the control needed to tell shell churn from widget churn. +await page.locator("[data-homarr-dev-benchmark-board]").waitFor({ state: "attached", timeout: 120_000 }); await page .waitForFunction( () => { const items = [...document.querySelectorAll('[data-type="item"]')]; - return ( - items.length > 0 && - items.every((item) => item.querySelector("[data-homarr-widget-ready],[data-homarr-widget-error]")) - ); + // An empty board legitimately has zero items; only require settling if any exist. + return items.every((item) => item.querySelector("[data-homarr-widget-ready],[data-homarr-widget-error]")); }, undefined, { timeout: 120_000 }, @@ -154,9 +167,11 @@ const stats = await page.evaluate(() => { byComponent: Map<string, number>; roots: Map<string, number>; started: number; + sawTimings: boolean; }; return { commits: state.commits, + sawTimings: (state as unknown as { sawTimings: boolean }).sawTimings, elapsedMs: Date.now() - state.started, top: [...state.byComponent.entries()].sort((a, b) => b[1] - a[1]).slice(0, 20), roots: [...state.roots.entries()].sort((a, b) => b[1] - a[1]).slice(0, 12), @@ -167,9 +182,19 @@ const perMinute = (stats.commits / stats.elapsedMs) * 60_000; console.log( `\ncommits while idle: ${stats.commits} over ${(stats.elapsedMs / 1000).toFixed(0)}s (${perMinute.toFixed(1)}/min)`, ); -console.log("\nupdate entered the tree at (commit roots):"); -for (const [name, count] of stats.roots) console.log(String(count).padStart(8), ` ${name}`); -console.log("\nre-renders by component:"); -for (const [name, count] of stats.top) console.log(String(count).padStart(8), ` ${name}`); +if (!stats.sawTimings) { + // Without this the empty tables below read as "nothing re-rendered", which is the + // opposite of the truth when the commit count is high. + console.log( + `\nNO PER-COMPONENT ATTRIBUTION: this is a production React build, which does not populate` + + `\nfiber.actualDuration. The commit count above is still valid. For attribution, build with` + + `\n docker build --build-arg HOMARR_PROFILING=true . -t homarr:performance`, + ); +} else { + console.log("\nupdate entered the tree at (commit roots):"); + for (const [name, count] of stats.roots) console.log(String(count).padStart(8), ` ${name}`); + console.log("\nre-renders by component:"); + for (const [name, count] of stats.top) console.log(String(count).padStart(8), ` ${name}`); +} console.log(`\n${JSON.stringify({ commits: stats.commits, perMinute: Number(perMinute.toFixed(1)) })}`); await browser.close(); diff --git a/scripts/benchmarks/measure-widget-churn.mts b/scripts/benchmarks/measure-widget-churn.mts new file mode 100644 index 000000000..d62037dd4 --- /dev/null +++ b/scripts/benchmarks/measure-widget-churn.mts @@ -0,0 +1,95 @@ +/** + * Attributes idle re-render churn to individual widgets, on a production build. + * + * `measure-rerenders.mts` counts React commits but cannot say which component caused them: + * attribution needs `fiber.actualDuration`, which only a React profiling build populates. + * DOM mutations need no such thing. Every re-render that changes anything observable shows up + * as a mutation, and the mutated node's nearest `[data-type="item"]` ancestor names the widget. + * + * This is what established that idle churn is widget-driven rather than app-shell driven: a + * board with 3 items commits 0 times per minute while a 28-item board commits 76. + * + * STRESS_BASE_URL=http://127.0.0.1:PORT STRESS_BOARD=default \ + * node --experimental-strip-types scripts/benchmarks/measure-widget-churn.mts + */ +import { chromium } from "@playwright/test"; + +const baseUrl = process.env.STRESS_BASE_URL; +if (!baseUrl) throw new Error("STRESS_BASE_URL is required"); +const username = process.env.STRESS_USERNAME ?? "demo"; +const password = process.env.STRESS_PASSWORD ?? "demodemo"; +const boardName = process.env.STRESS_BOARD ?? "default"; +const observeMs = Number(process.env.CHURN_OBSERVE_MS ?? 45_000); + +const browser = await chromium.launch(); +const context = await browser.newContext({ viewport: { width: 1920, height: 1080 } }); +const page = await context.newPage(); + +await page.goto(`${baseUrl}/auth/login`, { waitUntil: "networkidle" }); +await page.getByLabel("Username").fill(username); +await page.locator("#password").fill(password); +await page.locator("css=button[type='submit']").click(); +await page.waitForFunction(() => !window.location.pathname.includes("/auth/login"), undefined, { timeout: 60_000 }); + +await page.goto(`${baseUrl}/boards/${boardName}`, { waitUntil: "domcontentloaded" }); +await page.locator("[data-homarr-dev-benchmark-board]").waitFor({ state: "attached", timeout: 120_000 }); +await page + .waitForFunction( + () => { + const items = [...document.querySelectorAll('[data-type="item"]')]; + return items.every((item) => item.querySelector("[data-homarr-widget-ready],[data-homarr-widget-error]")); + }, + undefined, + { timeout: 120_000 }, + ) + .catch(() => console.log("warn: widgets did not all settle")); + +// Let the initial render storm finish before counting steady-state churn. +await page.waitForTimeout(5_000); + +const result = await page.evaluate(async (durationMs) => { + /** Names a widget from whatever the item element carries, falling back to its classes. */ + const describe = (item: Element | null) => { + if (!item) return "(outside any widget)"; + const attributes = [...item.attributes] + .filter((attribute) => /kind|widget|type|id/i.test(attribute.name) && attribute.value.length < 60) + .map((attribute) => `${attribute.name}=${attribute.value}`); + const marker = item.querySelector("[class*='-widget'],[class*='widget-']"); + const className = marker?.className; + const hint = typeof className === "string" ? className.split(/\s+/).find((part) => part.includes("widget")) : ""; + return `${hint ?? ""} ${attributes.join(" ")}`.trim() || "(unidentified item)"; + }; + + const counts = new Map<string, number>(); + let total = 0; + const observer = new MutationObserver((records) => { + for (const record of records) { + total++; + const node = record.target.nodeType === 1 ? (record.target as Element) : record.target.parentElement; + const key = describe(node?.closest('[data-type="item"]') ?? null); + counts.set(key, (counts.get(key) ?? 0) + 1); + } + }); + observer.observe(document.body, { + subtree: true, + childList: true, + attributes: true, + characterData: true, + }); + + await new Promise((resolve) => setTimeout(resolve, durationMs)); + observer.disconnect(); + + return { + total, + itemCount: document.querySelectorAll('[data-type="item"]').length, + byWidget: [...counts.entries()].sort((a, b) => b[1] - a[1]).slice(0, 20), + }; +}, observeMs); + +console.log(`\nboard "${boardName}": ${result.itemCount} items, observed idle for ${observeMs / 1000}s`); +console.log(`DOM mutations while idle: ${result.total} (${((result.total / observeMs) * 60_000).toFixed(0)}/min)\n`); +console.log(`${"mutations".padStart(10)} widget`); +for (const [name, count] of result.byWidget) console.log(`${String(count).padStart(10)} ${name.slice(0, 100)}`); + +await browser.close();