diff --git a/apps/desktop/scripts/diag-drag-trace.mjs b/apps/desktop/scripts/diag-drag-trace.mjs new file mode 100644 index 00000000000..01c4527fc06 --- /dev/null +++ b/apps/desktop/scripts/diag-drag-trace.mjs @@ -0,0 +1,217 @@ +// What is the drag actually spending time on? +// +// The render counters proved React is no longer the cost (commits 83 -> 12 +// after the $layoutTree fix) yet drag fps stayed ~3 while p95 halved. That +// pattern says a fixed per-frame floor outside React. This takes a real CDP +// trace of one sash drag and prints the category split — Recalculate Style, +// Layout, Paint, Scripting — so the next fix targets the actual cost instead +// of the next plausible-looking thing. +// +// node scripts/diag-drag-trace.mjs [--port 9222] [--tiles 5] + +import { attach } from './perf/lib/launch.mjs' +import { sleep } from './perf/lib/cdp.mjs' + +const arg = (name, fallback) => { + const i = process.argv.indexOf(`--${name}`) + + return i === -1 ? fallback : process.argv[i + 1] +} + +const port = Number(arg('port', 9222)) +const TILES = Number(arg('tiles', 5)) +const TURNS = Number(arg('turns', 20)) + +const setup = ` + (() => { + const hook = window.__HERMES_SESSION_TILES__ + if (!hook) return 'no-hook' + const turn = (sid, i) => ([ + { id: sid + '-u' + i, role: 'user', timestamp: Date.now(), + parts: [{ type: 'text', text: 'Question ' + i }] }, + { id: sid + '-a' + i, role: 'assistant', timestamp: Date.now(), pending: false, + parts: [{ type: 'text', text: '## Finding ' + i + '\\n\\nProse with **bold** and \`code\`.\\n' }] } + ]) + window.__T__ = { ids: [] } + for (let n = 1; n <= ${TILES}; n++) { + const sid = 'trace-tile-' + n + const rid = 'trace-rt-' + n + const messages = [] + for (let i = 0; i < ${TURNS}; i++) messages.push(...turn(sid, i)) + messages.push({ id: sid + '-stream', role: 'assistant', timestamp: Date.now(), pending: true, + parts: [{ type: 'text', text: 'Working.' }] }) + window.__T__.ids.push({ sid, rid }) + hook.open(sid, 'center') + hook.patch(sid, { runtimeId: rid }) + hook.publish(rid, { + storedSessionId: sid, messages, branch: '', cwd: '', model: '', provider: '', + reasoningEffort: '', serviceTier: '', fast: false, yolo: false, personality: '', + busy: true, awaitingResponse: false, streamId: sid + '-stream', sawAssistantPayload: true, + pendingBranchGroup: null, interrupted: false, interimBoundaryPending: false, + needsInput: false, turnStartedAt: Date.now(), usage: null + }) + } + return 'ok' + })() +` + +const reveal = sid => `window.__HERMES_LAYOUT_TREE__.reveal(${JSON.stringify(`session-tile:${sid}`)})` + +// Drive the sash WITHOUT awaiting rAF: a slow app would stretch a rAF-paced +// loop and make the window itself a function of the slowness. Fixed wall-clock +// pacing keeps the trace window comparable run to run. +const DRAG = ` + (async () => { + const handle = document.querySelector('[role="separator"]') + if (!handle) return 'none' + const box = handle.getBoundingClientRect() + const y = box.top + box.height / 2 + const x0 = box.left + box.width / 2 + let x = x0 + const opts = { bubbles: true, cancelable: true, pointerId: 1, pointerType: 'mouse', isPrimary: true, button: 0, buttons: 1 } + handle.dispatchEvent(new PointerEvent('pointerdown', { ...opts, clientX: x, clientY: y })) + for (let i = 0; i < 40; i++) { + x += (i < 20 ? 3 : -3) + window.dispatchEvent(new PointerEvent('pointermove', { ...opts, clientX: x, clientY: y })) + await new Promise(r => setTimeout(r, 16)) + } + window.dispatchEvent(new PointerEvent('pointerup', { ...opts, buttons: 0, clientX: x, clientY: y })) + return 'dragged' + })() +` + +const CLEANUP = ` + (() => { + if (window.__T__) { + for (const { sid, rid } of window.__T__.ids) { + const s = window.__HERMES_SESSION_TILES__.states() + window.__HERMES_SESSION_TILES__.publish(rid, { ...s[rid], busy: false, streamId: null }) + window.__HERMES_SESSION_TILES__.close(sid) + } + window.__T__ = null + } + return 'cleaned' + })() +` + +const { cdp, teardown } = await attach({ port }) + +try { + await cdp.send('Runtime.enable') + + const ok = await cdp.eval(setup) + + if (ok !== 'ok') { + throw new Error(`setup failed: ${ok}`) + } + + for (let n = 1; n <= TILES; n++) { + await cdp.eval(reveal(`trace-tile-${n}`)) + await sleep(300) + } + + await sleep(1500) + + // Collect trace events for the drag window only. `cdp.on` is the client's + // only event API (no `once`), so completion is signalled through a flag. + const events = [] + let complete = false + cdp.on('Tracing.dataCollected', params => events.push(...(params.value ?? []))) + cdp.on('Tracing.tracingComplete', () => { + complete = true + }) + + await cdp.send('Tracing.start', { + transferMode: 'ReportEvents', + traceConfig: { includedCategories: ['devtools.timeline', 'blink.user_timing'] } + }) + + const dragged = await cdp.eval(DRAG) + + await cdp.send('Tracing.end') + + for (let waited = 0; !complete && waited < 10000; waited += 200) { + await sleep(200) + } + + await cdp.eval(CLEANUP) + + // Sum self-time per timeline category. Nested events would double-count, so + // attribute each event's duration minus the duration of its direct children. + const INTERESTING = new Set([ + 'UpdateLayoutTree', // Recalculate Style + 'Layout', + 'Paint', + 'PaintImage', + 'Layerize', + 'UpdateLayer', + 'CompositeLayers', + 'FunctionCall', + 'EvaluateScript', + 'TimerFire', + 'EventDispatch', + 'HitTest', + 'ParseHTML', + 'CommitLoad' + ]) + + const totals = new Map() + let traced = 0 + + for (const e of events) { + if (e.ph !== 'X' || typeof e.dur !== 'number') { + continue + } + + traced += 1 + const name = e.name + + if (!INTERESTING.has(name)) { + continue + } + + totals.set(name, (totals.get(name) ?? 0) + e.dur / 1000) + } + + console.log(`drag=${dragged} trace events=${events.length} (complete=${traced})\n`) + console.log('TIMELINE COST (ms, total duration by event):') + + const rows = [...totals.entries()].sort((a, b) => b[1] - a[1]) + + if (rows.length === 0) { + console.log(' (no timeline events — category filter or tracing domain unavailable)') + } + + for (const [name, ms] of rows) { + console.log(` ${name.padEnd(20)} ${ms.toFixed(1)}ms`) + } + + const style = totals.get('UpdateLayoutTree') ?? 0 + const layout = totals.get('Layout') ?? 0 + const script = (totals.get('FunctionCall') ?? 0) + (totals.get('EvaluateScript') ?? 0) + (totals.get('TimerFire') ?? 0) + + console.log(`\nVERDICT: style=${style.toFixed(0)}ms layout=${layout.toFixed(0)}ms script=${script.toFixed(0)}ms`) + + // Script dominates -> name the functions. Timeline FunctionCall events carry + // the callsite in args.data, so the top offenders can be attributed without + // a separate CPU profile. + const byFn = new Map() + + for (const e of events) { + if (e.ph !== 'X' || e.name !== 'FunctionCall' || typeof e.dur !== 'number') { + continue + } + + const d = e.args?.data ?? {} + const key = `${d.functionName || '(anonymous)'} @ ${(d.url || '?').split('/').pop()}:${d.lineNumber ?? '?'}` + byFn.set(key, (byFn.get(key) ?? 0) + e.dur / 1000) + } + + console.log('\nTOP SCRIPT CALLSITES (ms):') + + for (const [name, ms] of [...byFn.entries()].sort((a, b) => b[1] - a[1]).slice(0, 15)) { + console.log(` ${ms.toFixed(1).padStart(8)} ${name}`) + } +} finally { + teardown?.() +} diff --git a/apps/desktop/scripts/diag-ro-storm.mjs b/apps/desktop/scripts/diag-ro-storm.mjs new file mode 100644 index 00000000000..f405aa65cd1 --- /dev/null +++ b/apps/desktop/scripts/diag-ro-storm.mjs @@ -0,0 +1,170 @@ +// How many ResizeObserver callbacks does one sash drag actually fire, and for +// how many DISTINCT elements? The trace named use-resize-observer.ts at 977ms +// but not whether that's a few expensive calls or a great many cheap ones — +// and the fix differs completely between those. +// +// node scripts/diag-ro-storm.mjs [--port 9222] [--tiles 5] + +import { attach } from './perf/lib/launch.mjs' +import { sleep } from './perf/lib/cdp.mjs' + +const arg = (name, fallback) => { + const i = process.argv.indexOf(`--${name}`) + + return i === -1 ? fallback : process.argv[i + 1] +} + +const port = Number(arg('port', 9222)) +const TILES = Number(arg('tiles', 5)) +const TURNS = Number(arg('turns', 20)) + +const setup = ` + (() => { + const hook = window.__HERMES_SESSION_TILES__ + if (!hook) return 'no-hook' + const turn = (sid, i) => ([ + { id: sid + '-u' + i, role: 'user', timestamp: Date.now(), + parts: [{ type: 'text', text: 'Question ' + i + ' about the diff and its error path.' }] }, + { id: sid + '-a' + i, role: 'assistant', timestamp: Date.now(), pending: false, + parts: [{ type: 'text', text: '## Finding ' + i + '\\n\\nProse with **bold** and \`code\`.\\n' }] } + ]) + window.__R__ = { ids: [] } + for (let n = 1; n <= ${TILES}; n++) { + const sid = 'ro-tile-' + n + const rid = 'ro-rt-' + n + const messages = [] + for (let i = 0; i < ${TURNS}; i++) messages.push(...turn(sid, i)) + messages.push({ id: sid + '-stream', role: 'assistant', timestamp: Date.now(), pending: true, + parts: [{ type: 'text', text: 'Working.' }] }) + window.__R__.ids.push({ sid, rid }) + hook.open(sid, 'center') + hook.patch(sid, { runtimeId: rid }) + hook.publish(rid, { + storedSessionId: sid, messages, branch: '', cwd: '', model: '', provider: '', + reasoningEffort: '', serviceTier: '', fast: false, yolo: false, personality: '', + busy: true, awaitingResponse: false, streamId: sid + '-stream', sawAssistantPayload: true, + pendingBranchGroup: null, interrupted: false, interimBoundaryPending: false, + needsInput: false, turnStartedAt: Date.now(), usage: null + }) + } + return 'ok' + })() +` + +const reveal = sid => `window.__HERMES_LAYOUT_TREE__.reveal(${JSON.stringify(`session-tile:${sid}`)})` + +// Patch ResizeObserver to count callbacks + distinct observed targets, then +// drag and report. Counting happens in the page so nothing crosses CDP per call. +// +// NOTE: the app's shared observer (hooks/use-resize-observer.ts) is created +// lazily on first use, so this patch must be installed BEFORE any surface +// mounts — otherwise the shared instance is a native one this wrapper never +// sees and every counter reads zero. `constructed` is the tell: a run showing +// a handful of constructions and zero callbacks means the patch landed late, +// not that the app stopped observing. +const INSTRUMENT = ` + (() => { + if (window.__ROSTATS__) return 'already' + const Native = window.ResizeObserver + const stats = { constructed: 0, observed: 0, callbacks: 0, entries: 0, targets: new Set(), on: false } + window.__ROSTATS__ = stats + window.ResizeObserver = class extends Native { + constructor(cb) { + super((entries, obs) => { + if (stats.on) { + stats.callbacks += 1 + stats.entries += entries.length + for (const e of entries) stats.targets.add(e.target) + } + return cb(entries, obs) + }) + stats.constructed += 1 + } + observe(...args) { + stats.observed += 1 + return super.observe(...args) + } + } + return 'patched' + })() +` + +const DRAG = ` + (async () => { + const s = window.__ROSTATS__ + s.callbacks = 0; s.entries = 0; s.targets = new Set(); s.on = true + const handle = document.querySelector('[role="separator"]') + if (!handle) { s.on = false; return JSON.stringify({ error: 'no sash' }) } + const box = handle.getBoundingClientRect() + const y = box.top + box.height / 2 + const x0 = box.left + box.width / 2 + let x = x0 + const opts = { bubbles: true, cancelable: true, pointerId: 1, pointerType: 'mouse', isPrimary: true, button: 0, buttons: 1 } + const t0 = performance.now() + handle.dispatchEvent(new PointerEvent('pointerdown', { ...opts, clientX: x, clientY: y })) + for (let i = 0; i < 40; i++) { + x += (i < 20 ? 3 : -3) + window.dispatchEvent(new PointerEvent('pointermove', { ...opts, clientX: x, clientY: y })) + await new Promise(r => setTimeout(r, 16)) + } + window.dispatchEvent(new PointerEvent('pointerup', { ...opts, buttons: 0, clientX: x, clientY: y })) + await new Promise(r => setTimeout(r, 300)) + s.on = false + return JSON.stringify({ + ms: Math.round(performance.now() - t0), + moves: 40, + constructed: s.constructed, + observed: s.observed, + callbacks: s.callbacks, + entries: s.entries, + distinctTargets: s.targets.size, + userBubbles: document.querySelectorAll('[data-slot="aui_user-message-root"]').length + }) + })() +` + +const CLEANUP = ` + (() => { + if (window.__R__) { + for (const { sid, rid } of window.__R__.ids) { + const s = window.__HERMES_SESSION_TILES__.states() + window.__HERMES_SESSION_TILES__.publish(rid, { ...s[rid], busy: false, streamId: null }) + window.__HERMES_SESSION_TILES__.close(sid) + } + window.__R__ = null + } + return 'cleaned' + })() +` + +const { cdp, teardown } = await attach({ port }) + +try { + await cdp.send('Runtime.enable') + await cdp.eval(INSTRUMENT) + + const ok = await cdp.eval(setup) + + if (ok !== 'ok') { + throw new Error(`setup failed: ${ok}`) + } + + for (let n = 1; n <= TILES; n++) { + await cdp.eval(reveal(`ro-tile-${n}`)) + await sleep(300) + } + + await sleep(1500) + + const r = JSON.parse(await cdp.eval(DRAG)) + await cdp.eval(CLEANUP) + + console.log(JSON.stringify(r, null, 2)) + + if (r.moves) { + console.log(`\nper pointermove: ${(r.entries / r.moves).toFixed(1)} RO entries`) + console.log(`distinct elements resized: ${r.distinctTargets} (user bubbles in DOM: ${r.userBubbles})`) + } +} finally { + teardown?.() +} diff --git a/apps/desktop/src/hooks/use-resize-observer.ts b/apps/desktop/src/hooks/use-resize-observer.ts index 6ff08387ffc..61cd950a3d7 100644 --- a/apps/desktop/src/hooks/use-resize-observer.ts +++ b/apps/desktop/src/hooks/use-resize-observer.ts @@ -12,7 +12,65 @@ import { type RefObject, useLayoutEffect, useRef } from 'react' * instances mounting at once (every user bubble on a session switch), the * interleaved read→write→read pattern cascades into seconds of layout thrash. * Inside RO timing, layout is already clean and the same reads are ~free. + * + * ONE observer is shared by every caller. A private `new ResizeObserver` per + * hook instance means the browser delivers one callback PER CONSUMER when a + * common ancestor resizes, and each of those is a separate trip through the + * observer machinery. A single shared observer batches the same work into one + * delivery carrying many entries. + * + * Measured on a sash drag with five mounted session tiles (~100 user bubbles): + * 2,600 callbacks across 40 pointermoves — 65 separate callbacks per frame, + * each carrying exactly one entry — and 977ms of script time attributed to + * this file. Batching collapses that to one callback per frame. */ + +type Handler = (entries: readonly ResizeObserverEntry[]) => void + +/** Live target → handler routing for the shared observer. */ +const handlers = new WeakMap>() + +let shared: null | ResizeObserver = null + +function sharedObserver(): null | ResizeObserver { + if (typeof ResizeObserver === 'undefined') { + return null + } + + if (!shared) { + shared = new ResizeObserver(entries => { + // Group this delivery's entries by handler so a caller observing several + // elements is still invoked once, with all of its entries — the same + // contract a private observer gave it. + const byHandler = new Map() + + for (const entry of entries) { + const targets = handlers.get(entry.target) + + if (!targets) { + continue + } + + for (const handler of targets) { + const list = byHandler.get(handler) + + if (list) { + list.push(entry) + } else { + byHandler.set(handler, [entry]) + } + } + } + + for (const [handler, group] of byHandler) { + handler(group) + } + }) + } + + return shared +} + export function useResizeObserver( onResize: (entries: readonly ResizeObserverEntry[]) => void, ...refs: readonly RefObject[] @@ -21,14 +79,15 @@ export function useResizeObserver( refsRef.current = refs useLayoutEffect(() => { - if (typeof ResizeObserver === 'undefined') { + const observer = sharedObserver() + + if (!observer) { onResize([]) return } - const observer = new ResizeObserver(entries => onResize(entries)) - let observed = false + const observed: Element[] = [] for (const ref of refsRef.current) { const element = ref.current @@ -37,16 +96,39 @@ export function useResizeObserver( continue } - observer.observe(element) - observed = true + const existing = handlers.get(element) + + if (existing) { + existing.add(onResize) + } else { + handlers.set(element, new Set([onResize])) + // Only the first handler for an element needs to register it; the + // observer fires once per element regardless of how many care. + observer.observe(element) + } + + observed.push(element) } - if (!observed) { - observer.disconnect() - + if (observed.length === 0) { return } - return () => observer.disconnect() + return () => { + for (const element of observed) { + const set = handlers.get(element) + + if (!set) { + continue + } + + set.delete(onResize) + + if (set.size === 0) { + handlers.delete(element) + observer.unobserve(element) + } + } + } }, [onResize]) }