// How smooth is a wheel scroll through the live feed? Drives Adam's own // Chrome (--remote-debugging-port=9222) with REAL mouse-wheel events through // CDP, switches feeds while they are still loading (the moment that feels // worst), and records what the page actually did: frame gaps from a rAF // loop, long tasks, the wheel events' input delay, row churn in the feed, // plus a CPU profile across the whole run so each long stretch is named. // // bun tools/feed-scroll-jank.js # Popular, Garden, Following // bun tools/feed-scroll-jank.js --feeds Popular,Following --seconds 6 // bun tools/feed-scroll-jank.js --trackpad # also the native (non-notch) wheel path // bun tools/feed-scroll-jank.js --match v3.coinos.io # which tab (default: v3 if open, else localhost) // bun tools/feed-scroll-jank.js --out dir # keep run.json + run.cpuprofile there // bun tools/feed-scroll-jank.js --trace --only settled --feeds Popular --seconds 15 // bun tools/feed-scroll-jank.js --coast --only coast --trace # quick-notch bursts, then hands off: dips/jumps in the coast + what landed // bun tools/feed-scroll-jank.js --url /feed/t/photography --feeds '#photography' --coast --only coast # a never-seen topic feed (fresh pictures) // # + a Chrome trace: names the browser work (image decode, layout, paint, GC…) inside each long frame // // Two kinds of scenario per feed: "switch" (click the chip, start turning the // wheel at once while posts arrive) and "settled" (same feed after it has // been quiet a few seconds) — the difference is the loading cost. The tab // must be visible: a hidden tab gets no frames and the numbers mean nothing. const args = Object.fromEntries(process.argv.slice(2).map((a, i, arr) => a.startsWith('--') ? [a.slice(2), arr[i + 1] && !arr[i + 1].startsWith('--') ? arr[i + 1] : true] : []).filter(Boolean)); const port = args.port || 9222; const seconds = Number(args.seconds || 5); const feeds = String(args.feeds || 'Popular,Garden,Following').split(',').map((s) => s.trim()).filter(Boolean); const notchMs = Number(args.cadence || 90); // ms between notches: a steady, fairly quick turn const sleep = (ms) => new Promise((r) => setTimeout(r, ms)); if (args.analyze) { const fs = await import('fs'); const saved = JSON.parse(fs.readFileSync(`${args.analyze}/run.json`, 'utf8')); for (const r of saved.results) console.log(` ${r.name.padEnd(26)} ${summarize(r)}`); analyze(JSON.parse(fs.readFileSync(`${args.analyze}/run.cpuprofile`, 'utf8')), saved.results, saved.profT0); process.exit(0); } // ---- the tab const list = await (await fetch(`http://localhost:${port}/json/list`)).json(); const pages = list.filter((t) => t.type === 'page'); const page = args.match ? pages.find((t) => t.url.includes(args.match)) : pages.find((t) => t.url.includes('v3.coinos.io')) || pages.find((t) => /localhost:5173/.test(t.url)); if (!page) { console.error('no page tab; open ones:', pages.map((p) => p.url).join(' ')); process.exit(1); } const ws = new WebSocket(page.webSocketDebuggerUrl); let id = 0; const pending = new Map(); const traceEvents = []; let traceDone = null; ws.onmessage = (m) => { const d = JSON.parse(m.data); if (d.id && pending.has(d.id)) { const { res, rej } = pending.get(d.id); pending.delete(d.id); d.error ? rej(new Error(JSON.stringify(d.error))) : res(d.result); } else if (d.method === 'Tracing.dataCollected') traceEvents.push(...d.params.value); else if (d.method === 'Tracing.tracingComplete' && traceDone) traceDone(); }; const send = (method, params = {}) => new Promise((res, rej) => { const i = ++id; pending.set(i, { res, rej }); ws.send(JSON.stringify({ id: i, method, params })); }); await new Promise((r) => (ws.onopen = r)); await send('Runtime.enable'); await send('Page.enable'); await send('Profiler.enable'); const ev = async (expression) => { const r = await send('Runtime.evaluate', { expression, returnByValue: true, awaitPromise: true }); if (r.exceptionDetails) throw new Error(r.exceptionDetails.exception?.description || r.exceptionDetails.text); return r.result.value; }; if (args.url) { // a fresh page: a topic feed nobody has scrolled yet, say /feed/t/photography await send('Page.navigate', { url: new URL(args.url, page.url).href }); await sleep(Number(args.settle || 9000)); } const vis = await ev('document.visibilityState'); if (vis !== 'visible') { console.error(`the tab is ${vis}; bring it to the front (a hidden tab gets no frames)`); process.exit(1); } if (!(await ev(`!!document.querySelector('.feed-chips')`))) { // not on the feed: the bottom-nav Feed button takes us there await ev(`(() => { const b = [...document.querySelectorAll('.app-nav-button')].find((x) => /feed/i.test(x.textContent)); if (b) b.click(); return !!b; })()`); await sleep(1500); if (!(await ev(`!!document.querySelector('.feed-chips')`))) { console.error('could not reach the feed page'); process.exit(1); } } // ---- the recorder, inside the page await ev(`(() => { const R = window.__jank = { frames: [], tasks: [], wheel: [], rows: { added: 0, removed: 0, batches: 0 }, live: false }; R.start = () => { R.frames = []; R.tasks = []; R.wheel = []; R.rows = { added: 0, removed: 0, batches: 0 }; R.live = true; R.t0 = performance.now(); R.y0 = scrollY; const tick = (t) => { if (!R.live) return; R.frames.push([t, scrollY, document.documentElement.scrollHeight]); requestAnimationFrame(tick); }; requestAnimationFrame(tick); R.lt = new PerformanceObserver((l) => { for (const e of l.getEntries()) R.tasks.push([e.startTime, e.duration]); }); R.lt.observe({ type: 'longtask', buffered: false }); try { R.et = new PerformanceObserver((l) => { for (const e of l.getEntries()) if (e.name === 'wheel') R.wheel.push([e.startTime, e.processingStart - e.startTime, e.duration]); }); R.et.observe({ type: 'event', durationThreshold: 16, buffered: false }); } catch {} const feed = document.querySelector('.notes-feed'); R.batches = []; R.loads = []; R.shifts = []; R.wheels = []; R.mo = new MutationObserver((muts) => { let a = 0, r = 0; for (const m of muts) { a += m.addedNodes.length; r += m.removedNodes.length; } if (a || r) { R.rows.batches++; R.rows.added += a; R.rows.removed += r; R.batches.push([performance.now(), a, r]); } }); if (feed) R.mo.observe(feed, { childList: true }); // a picture or clip landing: when, how big, where on screen R.onLoad = (e) => { const el = e.target; if (!el || !/^(IMG|VIDEO)$/.test(el.tagName) || !el.closest('.notes-feed')) return; const b = el.getBoundingClientRect(); R.loads.push([performance.now(), el.tagName, el.naturalWidth || el.videoWidth || 0, el.naturalHeight || el.videoHeight || 0, Math.round(b.top), Math.round(b.height), (el.currentSrc || el.src || '').split('//').pop().slice(0, 50)]); }; document.addEventListener('load', R.onLoad, true); document.addEventListener('loadedmetadata', R.onLoad, true); try { R.ls = new PerformanceObserver((l) => { for (const e of l.getEntries()) R.shifts.push([e.startTime, +e.value.toFixed(4), e.hadRecentInput, (e.sources || []).map((s) => s.node?.tagName || '?').join('+')]); }); R.ls.observe({ type: 'layout-shift', buffered: false }); } catch {} R.onWheel = (e) => R.wheels.push(e.timeStamp); window.addEventListener('wheel', R.onWheel, { passive: true, capture: true }); // every programmatic scroll, with who asked: the coast's own steps come // from tick(); anything else in a frame is a correction fighting it R.scrolls = []; R._to = window.scrollTo; R._by = window.scrollBy; const rec = (kind, y0) => { const st = (new Error().stack || '').split(String.fromCharCode(10)); const who = (st.find((l, i) => i > 1 && !/scrollTo|scrollBy/.test(l)) || '').trim().split(' (')[0].slice(0, 40); R.scrolls.push([performance.now(), kind, Math.round(scrollY - y0), who]); }; window.scrollTo = function (...a) { const y0 = scrollY; R._to.apply(window, a); rec('to', y0); }; window.scrollBy = function (...a) { const y0 = scrollY; R._by.apply(window, a); rec('by', y0); }; }; R.stop = () => { R.live = false; R.lt?.disconnect(); R.et?.disconnect(); R.mo?.disconnect(); R.ls?.disconnect(); document.removeEventListener('load', R.onLoad, true); document.removeEventListener('loadedmetadata', R.onLoad, true); window.removeEventListener('wheel', R.onWheel, { capture: true }); if (R._to) { window.scrollTo = R._to; window.scrollBy = R._by; } return { t0: R.t0, t1: performance.now(), y0: R.y0, y1: scrollY, frames: R.frames, tasks: R.tasks, wheel: R.wheel, rows: R.rows, batches: R.batches, loads: R.loads, shifts: R.shifts, wheels: R.wheels, scrolls: R.scrolls, vh: innerHeight, timeOrigin: performance.timeOrigin, rowsNow: document.querySelectorAll('.notes-feed > .row').length, booting: !!document.querySelector('.notes-feed[data-booting]') }; }; return true; })()`); // ---- real input const feedRect = async () => ev(`(() => { const f = document.querySelector('.notes-feed') || document.querySelector('.feed-page'); if (!f) return { x: innerWidth / 2, y: innerHeight / 2, w: innerWidth, h: innerHeight }; const r = f.getBoundingClientRect(); return { x: r.x + r.width / 2, y: Math.max(120, Math.min(innerHeight - 80, r.y + r.height / 2)), w: innerWidth, h: innerHeight }; })()`); const wheel = async (x, y, deltaY) => send('Input.dispatchMouseEvent', { type: 'mouseWheel', x, y, deltaX: 0, deltaY }); const clickChip = async (label) => { await ev('window.scrollTo(0, 0)'); await sleep(250); // the chips sit at the top of the page const r = await ev(`(() => { const b = [...document.querySelectorAll('.feed-chips .feed-chip')].find((x) => x.textContent.trim().toLowerCase() === ${JSON.stringify(label.toLowerCase())}); if (!b) return null; b.scrollIntoView({ inline: 'center', block: 'nearest' }); const q = b.getBoundingClientRect(); return { x: q.x + q.width / 2, y: q.y + q.height / 2 }; })()`); if (!r) throw new Error(`no chip "${label}" (chips: ${await ev(`[...document.querySelectorAll('.feed-chips .feed-chip')].map((b) => b.textContent.trim()).join(' | ')`)})`); await send('Input.dispatchMouseEvent', { type: 'mouseMoved', x: r.x, y: r.y }); await send('Input.dispatchMouseEvent', { type: 'mousePressed', x: r.x, y: r.y, button: 'left', clickCount: 1 }); await send('Input.dispatchMouseEvent', { type: 'mouseReleased', x: r.x, y: r.y, button: 'left', clickCount: 1 }); }; // A notch: Chrome gives a synthetic deltaY of 100 a wheelDeltaY of -120, which // is what app.js treats as a mouse (it coasts the page itself). A trackpad // delta (not a multiple of 120) leaves the scroll native. const probe = await (async () => { const r = await feedRect(); await ev(`window.__probe = null; addEventListener('wheel', (e) => { window.__probe = { dy: e.deltaY, wdy: e.wheelDeltaY, mode: e.deltaMode }; e.preventDefault(); }, { once: true, passive: false })`); await wheel(r.x, r.y, 100); await sleep(50); return ev('window.__probe'); })(); console.log(`page=${page.url}\nwheel probe: deltaY=${probe?.dy} wheelDeltaY=${probe?.wdy} (${probe && probe.wdy % 120 === 0 ? 'notch → app coast' : 'NOT a notch'})`); // ---- scenarios const results = []; const delta = args.trackpad === true ? 100 : Number(args.delta || 100); async function scenario(name, { feed, switchTo, dy = 100 }) { const r = await feedRect(); await send('Input.dispatchMouseEvent', { type: 'mouseMoved', x: r.x, y: r.y }); const tStart = Date.now(); await ev('window.__jank.start()'); if (switchTo) await clickChip(switchTo); // turn the wheel steadily: down, then a stretch back up, then down again const n = Math.round(seconds * 1000 / notchMs); for (let i = 0; i < n; i++) { const dir = i >= n * 0.55 && i < n * 0.75 ? -1 : 1; await wheel(r.x, r.y, dir * dy); await sleep(notchMs); } await sleep(600); // let the coast die const rec = await ev('window.__jank.stop()'); rec.name = name; rec.feed = feed; rec.wall = [tStart, Date.now()]; results.push(rec); console.log(` ${name.padEnd(26)} ${summarize(rec)}`); } // A burst of quick notches, then hands off while it coasts; repeated down // the feed. What the reader feels as "it slows down" shows up here as frames // whose travel falls short of the coast's own decay (dips) or overshoots it // (jumps), next to what landed at that moment. async function coastScenario(name, { feed, bursts = 6, dy = 100 }) { const r = await feedRect(); await send('Input.dispatchMouseEvent', { type: 'mouseMoved', x: r.x, y: r.y }); const tStart = Date.now(); await ev('window.__jank.start()'); for (let b = 0; b < bursts; b++) { for (let i = 0; i < 6; i++) { await wheel(r.x, r.y, dy); await sleep(55); } await sleep(Number(args.coast || 2600)); } const rec = await ev('window.__jank.stop()'); rec.name = name; rec.feed = feed; rec.wall = [tStart, Date.now()]; rec.coast = true; results.push(rec); console.log(` ${name.padEnd(26)} ${summarize(rec)}`); coastReport(rec); } function coastReport(rec) { const F = rec.frames, dips = [], jumps = []; let lost = 0, travel = 0; const near = (t, list, w = 70) => list.filter((x) => Math.abs(x[0] - t) <= w); for (let i = 2; i < F.length; i++) { const dt = F[i][0] - F[i - 1][0], pdt = F[i - 1][0] - F[i - 2][0]; const dy = F[i][1] - F[i - 1][1], pdy = F[i - 1][1] - F[i - 2][1]; if (!pdt || !dt) continue; const expected = pdy * (dt / pdt) * Math.exp(-dt / 325); travel += Math.abs(dy); if (Math.abs(expected) < 4) continue; const afterWheel = rec.wheels.some((w) => F[i][0] - w >= 0 && F[i][0] - w < 120); if (Math.abs(dy) < 0.6 * Math.abs(expected)) { dips.push(i); lost += Math.abs(expected) - Math.abs(dy); } else if (!afterWheel && Math.abs(dy) > 1.6 * Math.abs(expected) + 3) jumps.push(i); } rec.s.dips = dips.length; rec.s.jumps = jumps.length; rec.s.lostPx = Math.round(lost); const what = (i) => { const t = F[i][0]; const out = []; const g = F[i][0] - F[i - 1][0]; if (g > 25) out.push(`frame ${g.toFixed(0)}ms`); if (F[i][2] != null) { const dh = F[i][2] - F[i - 1][2]; if (dh) out.push(`page ${dh > 0 ? 'grew' : 'shrank'} ${dh}px`); if (F[i][1] + rec.vh >= F[i][2] - 2) out.push('AT THE END of the page'); } const ld = near(t, rec.loads, 120); for (const l of ld.slice(0, 3)) out.push(`${l[1]} ${l[2]}x${l[3]} at top ${l[4]} h${l[5]} ${l[6]}`); if (ld.length > 3) out.push(`+${ld.length - 3} more loads`); for (const sh of near(t, rec.shifts)) out.push(`shift ${sh[1]}${sh[2] ? ' (input)' : ''} ${sh[3]}`); for (const b of near(t, rec.batches)) out.push(`rows +${b[1]} −${b[2]}`); for (const sc of (rec.scrolls || []).filter((x) => x[0] > F[i - 1][0] - 1 && x[0] <= t + 1 && !/tick/.test(x[3]))) out.push(`${sc[1] === 'to' ? 'scrollTo' : 'scrollBy'} ${sc[2]}px by ${sc[3] || '?'}`); for (const lt of rec.tasks) if (lt[0] <= t && lt[0] + lt[1] >= t - 70) out.push(`long task ${lt[1].toFixed(0)}ms`); return out.join('; ') || '(nothing recorded nearby)'; }; const show = (list, kind) => { for (const i of list.slice(0, Number(args.top || 14))) { const dy = F[i][1] - F[i - 1][1], pdy = F[i - 1][1] - F[i - 2][1]; console.log(` ${kind} @${(F[i][0] - rec.t0).toFixed(0).padStart(5)}ms ${pdy.toFixed(0)}→${dy.toFixed(0)}px/frame ${what(i)}`); } }; console.log(` coast: ${dips.length} dips (≈${Math.round(lost)}px of travel lost of ${Math.round(travel)}), ${jumps.length} jumps, ${rec.loads.length} media loads, ${rec.shifts.length} layout shifts`); show(dips, 'dip '); show(jumps, 'jump'); } function stats(gaps) { const s = [...gaps].sort((a, b) => a - b); const q = (p) => s.length ? s[Math.min(s.length - 1, Math.floor(s.length * p))] : 0; return { n: s.length, p50: q(0.5), p95: q(0.95), max: s.length ? s[s.length - 1] : 0 }; } function summarize(rec) { const gaps = rec.frames.slice(1).map((f, i) => f[0] - rec.frames[i][0]); const g = stats(gaps); const over = (ms) => gaps.filter((x) => x > ms).length; const lt = rec.tasks.reduce((a, t) => a + t[1], 0), ltMax = Math.max(0, ...rec.tasks.map((t) => t[1])); const wd = stats(rec.wheel.map((w) => w[1])); // a frozen frame while the page should be moving: nothing to show for >33 ms const stalls = gaps.filter((x) => x > 33).reduce((a, x) => a + x, 0); rec.s = { frames: g.n, p50: g.p50, p95: g.p95, max: g.max, over33: over(33), over50: over(50), over100: over(100), stalledMs: stalls, longTasks: rec.tasks.length, longTaskMs: lt, longTaskMax: ltMax, wheelSlow: rec.wheel.length, wheelDelayP95: wd.p95, moved: rec.y1 - rec.y0 }; return `frames=${g.n} p50=${g.p50.toFixed(1)} p95=${g.p95.toFixed(0)} max=${g.max.toFixed(0)}ms | >33ms:${over(33)} >50:${over(50)} >100:${over(100)} (stalled ${stalls.toFixed(0)}ms of ${(rec.t1 - rec.t0).toFixed(0)}) | long tasks ${rec.tasks.length} = ${lt.toFixed(0)}ms max ${ltMax.toFixed(0)} | wheel>16ms ${rec.wheel.length} delay p95 ${wd.p95.toFixed(0)} | rows +${rec.rows.added} −${rec.rows.removed} in ${rec.rows.batches} batches | moved ${rec.y1 - rec.y0}px`; } await send('Profiler.setSamplingInterval', { interval: Number(args.interval || 250) }); if (args.trace) await send('Tracing.start', { categories: 'devtools.timeline,disabled-by-default-devtools.timeline,disabled-by-default-devtools.timeline.frame,blink.user_timing,v8.execute', transferMode: 'ReportEvents' }); await send('Profiler.start'); const profT0 = await ev('performance.now()'); // a user-timing mark lands in the trace with the trace clock: the alignment const syncNow = await ev(`(() => { performance.mark('jank-sync'); return performance.now(); })()`); // where are we now: settle, then start from another feed so every switch is a real one const current = await ev(`(document.querySelector('.feed-chips .feed-chip.on') || {}).textContent?.trim()`); console.log(`current feed: ${current}\n== mouse wheel (notch, app coast) ==`); for (const f of (args.only === 'coast' ? [] : feeds)) { if (args.only !== 'settled') { if (current !== f || results.length) { await ev('window.scrollTo(0,0)'); await sleep(300); } await scenario(`switch → ${f}`, { feed: f, switchTo: f, dy: delta }); await sleep(4000); // let the feed settle } else if (current !== f) { await clickChip(f); await sleep(5000); } await ev('window.scrollTo(0,0)'); await sleep(400); await scenario(`settled ${f}`, { feed: f, dy: delta }); } if (args.coast) { console.log('== bursts then hands-off coast =='); for (const f of feeds) { const cur = await ev(`(document.querySelector('.feed-chips .feed-chip.on') || {}).textContent?.trim()`); if (cur !== f) { await clickChip(f); await sleep(5000); } await ev(`window.scrollTo(0,${Number(args.start || 0)})`); await sleep(args.start ? 1500 : 400); await coastScenario(`coast ${f}`, { feed: f, bursts: Number(args.bursts || 6) }); } } if (args.trackpad) { console.log('== trackpad-like (native scroll) =='); for (const f of feeds) { await ev('window.scrollTo(0,0)'); await sleep(300); await scenario(`switch → ${f} (native)`, { feed: f, switchTo: f, dy: 110 }); await sleep(4000); await ev('window.scrollTo(0,0)'); await sleep(400); await scenario(`settled ${f} (native)`, { feed: f, dy: 110 }); } } const { profile } = await send('Profiler.stop'); if (args.trace) { const done = new Promise((r) => (traceDone = r)); await send('Tracing.end'); await done; } ws.close(); if (args.out) { const fs = await import('fs'); fs.mkdirSync(args.out, { recursive: true }); fs.writeFileSync(`${args.out}/run.json`, JSON.stringify({ page: page.url, probe, results, profT0, syncNow }, null, 1)); fs.writeFileSync(`${args.out}/run.cpuprofile`, JSON.stringify(profile)); if (args.trace) fs.writeFileSync(`${args.out}/trace.json`, JSON.stringify({ traceEvents })); } analyze(profile, results, profT0); if (args.trace) analyzeTrace(traceEvents, results, syncNow); // ---- the browser's own work inside each long frame (from the trace) function analyzeTrace(events, results, syncNow) { const mark = events.find((e) => e.name === 'jank-sync' && e.cat.includes('blink.user_timing')); if (!mark) { console.log('\n(trace: no sync mark found; cannot align)'); return; } const pid = mark.pid, offset = mark.ts - syncNow * 1000; // page ms → trace µs const threads = new Map(); // tid → name for (const e of events) if (e.ph === 'M' && e.name === 'thread_name' && e.pid === pid) threads.set(e.tid, e.args.name); const mainTid = [...threads].find(([, n]) => n === 'CrRendererMain')?.[0]; // self time per complete event: its duration minus its children's const byThread = new Map(); for (const e of events) if (e.ph === 'X' && e.pid === pid && e.dur > 0) { if (!byThread.has(e.tid)) byThread.set(e.tid, []); byThread.get(e.tid).push(e); } const flat = []; for (const [tid, list] of byThread) { list.sort((a, b) => a.ts - b.ts || b.dur - a.dur); const stack = []; for (const e of list) { while (stack.length && stack[stack.length - 1].ts + stack[stack.length - 1].dur <= e.ts) stack.pop(); e.self = e.dur; if (stack.length) stack[stack.length - 1].self -= e.dur; e.main = tid === mainTid; e.thread = threads.get(tid) || String(tid); stack.push(e); flat.push(e); } } flat.sort((a, b) => a.ts - b.ts); const label = (e) => { const d = e.args?.data || e.args || {}; const extra = d.url ? ' ' + String(d.url).replace(/^https?:\/\//, '').slice(0, 60) : d.imageType ? ' ' + d.imageType : d.functionName ? ' ' + d.functionName : ''; return e.name + extra; }; // the display's own frame accounting: frames the compositor dropped even // while the page's animation frames kept ticking (a huge bitmap rasterizing) const pipes = events.filter((e) => e.name === 'PipelineReporter' && e.ph === 'b' && e.pid === pid && e.args?.chrome_frame_reporter); if (pipes.length) { console.log('\n== trace: display frames (compositor pipeline) per scenario =='); for (const r of results) { const A = r.t0 * 1000 + offset, B = r.t1 * 1000 + offset; const inWin = pipes.filter((e) => e.ts >= A && e.ts <= B); const st = new Map(); for (const e of inWin) { const k = e.args.chrome_frame_reporter.state; st.set(k, (st.get(k) || 0) + 1); } const dropped = inWin.filter((e) => e.args.chrome_frame_reporter.state === 'STATE_DROPPED'); // where in the scenario the dropped ones cluster (100 ms bins with ≥2) const bins = new Map(); for (const e of dropped) { const b = Math.floor((e.ts - A) / 100000); bins.set(b, (bins.get(b) || 0) + 1); } const clusters = [...bins].filter(([, n]) => n >= 2).sort((a, b) => b[1] - a[1]).slice(0, 10).map(([b, n]) => `${(b * 100)}ms×${n}`).join(' '); console.log(`${r.name}: ${[...st].map(([k, v]) => k.replace('STATE_', '') + ' ' + v).join(', ')}${clusters ? '\n dropped clusters: ' + clusters : ''}`); } } console.log('\n== trace: browser work inside the long frames (self ms; main thread unless marked) =='); for (const r of results) { const gaps = []; for (let i = 1; i < r.frames.length; i++) { const g = r.frames[i][0] - r.frames[i - 1][0]; if (g > 33) gaps.push([r.frames[i - 1][0], r.frames[i][0], g]); } if (!gaps.length) { console.log(`${r.name}: no long frames`); continue; } const tot = new Map(), totOff = new Map(); const lines = []; for (const [a, b, g] of gaps) { const A = a * 1000 + offset, B = b * 1000 + offset; const inside = flat.filter((e) => e.ts < B && e.ts + e.dur > A && e.self > 500); const per = new Map(); for (const e of inside) { const k = (e.main ? '' : '[' + e.thread + '] ') + label(e); const v = Math.min(e.self, Math.min(B, e.ts + e.dur) - Math.max(A, e.ts)); per.set(k, (per.get(k) || 0) + v); (e.main ? tot : totOff).set(e.name, ((e.main ? tot : totOff).get(e.name) || 0) + v); } const top = [...per].sort((x, y) => y[1] - x[1]).slice(0, 5).map(([k, v]) => `${k} ${(v / 1000).toFixed(0)}`).join(' | '); lines.push(` ${g.toFixed(0).padStart(4)}ms @${(a - r.t0).toFixed(0).padStart(5)}ms: ${top}`); } const sum = (m) => [...m].sort((x, y) => y[1] - x[1]).slice(0, 8).map(([k, v]) => `${k} ${(v / 1000).toFixed(0)}`).join(', '); console.log(`${r.name}: ${gaps.length} long frames\n main: ${sum(tot)}\n other threads: ${sum(totOff)}`); for (const l of lines.slice(0, Number(args.top || 14))) console.log(l); } } // ---- who was running during the long frames // Profile timestamps are µs on the same monotonic clock as performance.now() // (startTime ≈ timeOrigin + now); align by the sample we took at start. function analyze(profile, results, profT0) { const nodes = new Map(profile.nodes.map((n) => [n.id, n])); const fnKey = (n) => { const f = n.callFrame; return `${f.functionName || '(anon)'} ${f.url.replace(/^https?:\/\/[^/]+/, '').replace(/^\/assets\//, '')}:${f.lineNumber + 1}`; }; const samples = []; let t = profile.startTime; for (let i = 0; i < profile.samples.length; i++) { t += profile.timeDeltas[i]; samples.push([t, profile.samples[i], profile.timeDeltas[i + 1] || 0]); } const offsetUs = profile.startTime - profT0 * 1000; // page-ms → profile-µs const idleName = (n) => n.callFrame.functionName === '(idle)'; // busy runs in the profile: stretches of non-idle samples longer than 50 ms const profileParentMap = new Map(); for (const n of profile.nodes) for (const c of n.children || []) profileParentMap.set(c, n.id); const runs = []; let run = null; for (const [ts, nid, dt] of samples) { const n = nodes.get(nid); if (idleName(n)) { if (run) { runs.push(run); run = null; } continue; } if (!run) run = { start: ts, end: ts + dt, self: new Map(), total: new Map() }; run.end = ts + dt; const k = fnKey(n); run.self.set(k, (run.self.get(k) || 0) + dt); // inclusive: walk up const seen = new Set(); let p = nid; const parent = profileParentMap; while (p != null) { const kk = fnKey(nodes.get(p)); if (!seen.has(kk)) { seen.add(kk); run.total.set(kk, (run.total.get(kk) || 0) + dt); } p = parent.get(p); } } if (run) runs.push(run); const long = runs.filter((r) => r.end - r.start > Number(args.busy || 30) * 1000).sort((a, b) => (b.end - b.start) - (a.end - a.start)); const ms = (us) => (us / 1000).toFixed(0); const scenarioAt = (us) => { const pm = (us - offsetUs) / 1000; return results.find((r) => pm >= r.t0 && pm <= r.t1)?.name || '(between)'; }; console.log(`\n== busy stretches > ${args.busy || 30}ms (main thread never idle): ${long.length}, ${ms(long.reduce((a, r) => a + r.end - r.start, 0))}ms in all; the longest, who was inside ==`); for (const r of long.slice(0, Number(args.top || 14))) { const top = [...r.total].filter(([k]) => !/^\((root|program|garbage collector)\)/.test(k)).sort((a, b) => b[1] - a[1]).slice(0, 6).map(([k, v]) => `${k} ${ms(v)}`).join(' > '); const self = [...r.self].filter(([k]) => !/^\((root|program)\)/.test(k)).sort((a, b) => b[1] - a[1]).slice(0, 4).map(([k, v]) => `${k} ${ms(v)}`).join(', '); console.log(`${ms(r.end - r.start).padStart(5)}ms [${scenarioAt(r.start)}]\n inclusive: ${top}\n self: ${self}`); } // self time across all scenarios, by function const selfAll = new Map(); let busyAll = 0, wallAll = 0; for (const [ts, nid, dt] of samples) { wallAll += dt; const n = nodes.get(nid); if (idleName(n)) continue; busyAll += dt; const k = fnKey(n); selfAll.set(k, (selfAll.get(k) || 0) + dt); } console.log(`\n== self time over the run (busy ${ms(busyAll)}ms of ${ms(wallAll)}ms, ${(100 * busyAll / wallAll).toFixed(0)}%) ==`); for (const [k, v] of [...selfAll].sort((a, b) => b[1] - a[1]).slice(0, 18)) console.log(ms(v).padStart(7), k); // ---- the table const busyBy = new Map(); for (const r of long) { const k = scenarioAt(r.start); busyBy.set(k, (busyBy.get(k) || 0) + (r.end - r.start)); } console.log('\n== summary =='); console.log('scenario'.padEnd(28) + 'p95 max >33 >50 >100 stalled ltasks ltMax busy>' + (args.busy || 30) + ' rows±'); for (const r of results) { const s = r.s; console.log(r.name.padEnd(28) + (r.coast ? `dips ${s.dips} (${s.lostPx}px) jumps ${s.jumps} ` : '') + `${s.p95.toFixed(0).padStart(3)} ${s.max.toFixed(0).padStart(4)} ${String(s.over33).padStart(4)} ${String(s.over50).padStart(4)} ${String(s.over100).padStart(5)} ${(s.stalledMs.toFixed(0) + 'ms').padStart(7)} ${String(s.longTasks).padStart(6)} ${s.longTaskMax.toFixed(0).padStart(5)} ${(ms(busyBy.get(r.name) || 0) + 'ms').padStart(8)} +${r.rows.added}/−${r.rows.removed} in ${r.rows.batches}`); } if (args.out) console.log(`\nraw: ${args.out}/run.json, ${args.out}/run.cpuprofile (tools/cdp-callers.js for callers; --analyze ${args.out} re-reads them)`); }