diff options
| -rw-r--r-- | src/features/messages.js | 58 | ||||
| -rw-r--r-- | src/features/nostrlogin.js | 18 | ||||
| -rw-r--r-- | src/nostr.js | 11 | ||||
| -rw-r--r-- | tools/feed-scroll-jank.js | 222 |
4 files changed, 299 insertions, 10 deletions
diff --git a/src/features/messages.js b/src/features/messages.js index 94a5173..278e66f 100644 --- a/src/features/messages.js +++ b/src/features/messages.js @@ -4193,11 +4193,19 @@ export function messagesFeature(ctx) { // language); unknown is never translated unasked // A post that is only hashtags is judged by them: its tags in a script // the reader can't read are what wants translating (as glosses). + // Asked per row per render; the guess reads the whole text, and a post's + // text and the target language don't change, so remember it. + const foreignMemo = new Map(); const looksForeign = (ev) => { const to = transLang(); if (!translatable(ev) || !(deeplKey() || canTranslateTo(to))) return false; + const mk = transKey(ev) + '|' + to; + if (foreignMemo.has(mk)) return foreignMemo.get(mk); const text = noteText(ev), { prose, tags } = transParts(text, to); - return prose.length ? !inLanguage(text, to) : tags.length > 0; + const v = prose.length ? !inLanguage(text, to) : tags.length > 0; + if (foreignMemo.size > 3000) foreignMemo.clear(); + foreignMemo.set(mk, v); + return v; }; const langName = (code) => { try { return new Intl.DisplayNames([getLang()], { type: 'language' }).of(code) || code; } catch { return code; } }; // the translation to SHOW for this post now, or null @@ -4715,8 +4723,14 @@ export function messagesFeature(ctx) { // (a /username deep link over the unlock screen) scrolls too, and init // only runs once a wallet opens. let lastFeedY = 0, pillFrame = 0; + // When the reader last moved the page themselves (a wheel notch coasts for + // a while after the last one), and when it last scrolled at all: a batch of + // arriving posts waits for a quiet moment (see queueAdmit). + let lastInputAt = 0, lastScrollAt = 0; if (typeof window !== 'undefined') { + for (const n of ['wheel', 'touchstart', 'touchmove', 'keydown', 'pointerdown']) window.addEventListener(n, () => { lastInputAt = Date.now(); }, { passive: true, capture: true }); window.addEventListener('scroll', () => { + lastScrollAt = Date.now(); if (!ui.profilePk && (!(ui.chatOpen && ui.msgView === 'feed') || ui.noteThread)) return; windowScrolled(ui.profilePk ? notesCache.get(ui.profilePk) : feed); // back at the top by yourself: the new posts are under your eyes, so @@ -6707,12 +6721,37 @@ export function messagesFeature(ctx) { // Cached rows can still be warming. This new row is already prepared // and can take its stable presentation without waiting for that page. if (c.booting) { c.prepared ||= new Set(); c.prepared.add(e.id); } - admitFeed([...(c.deferred || []), e], c, false, opts.newerThan); - scheduleRepaint(); + queueAdmit(e, c, opts.newerThan); return true; })); return ready.some(Boolean); } + // Ready posts go in together: one admission — one render with the reader's + // row held still — per short interval, not one per post. A Popular switch + // used to run dozens of full renders in a few seconds, 200–450 ms each, + // and a wheel scroll through them stuttered on a laptop (the wheel coast + // is driven from the main thread, so every long render froze it). While + // the reader is moving the page the batch waits for a quiet moment, up to + // a cap, so nothing much changes under a coasting scroll. + const ADMIT_MS = 120, ADMIT_QUIET_MS = 160, ADMIT_INPUT_MS = 2500, ADMIT_MAX_WAIT_MS = 1500; + const admitQueues = new Map(); // c → { evs, newerThan, since, timer } + function queueAdmit(e, c, newerThan) { + let q = admitQueues.get(c); + if (!q) admitQueues.set(c, q = { evs: [], newerThan, since: Date.now(), timer: 0 }); + q.evs.push(e); + if (!q.timer) q.timer = setTimeout(() => flushAdmit(c), ADMIT_MS); + } + const readerMoving = () => Date.now() - lastScrollAt < ADMIT_QUIET_MS && Date.now() - lastInputAt < ADMIT_INPUT_MS; + function flushAdmit(c) { + const q = admitQueues.get(c); + if (!q) return; + q.timer = 0; + if (c === feed && readerMoving() && Date.now() - q.since < ADMIT_MAX_WAIT_MS) { q.timer = setTimeout(() => flushAdmit(c), ADMIT_QUIET_MS); return; } + admitQueues.delete(c); + if (c.stopped) return; + admitFeed([...(c.deferred || []), ...q.evs], c, false, q.newerThan); + scheduleRepaint(); + } // Never insert between the rows currently under the reader's eyes. Gap // fills wait until that part of the feed is offscreen; new posts above @@ -8706,7 +8745,10 @@ export function messagesFeature(ctx) { // rooms, DMs, quote cards. Two rules are Amethyst's, and are what makes // its feeds feel clean: repeated content from strangers is spam, and a // post your follows reported is folded (not hidden) behind who said so. - const modOn = (k) => (st().mod || {})[k] !== false; + // Per row per check; the cached copy serves (a Settings toggle writes + // through save(), which refreshes it) rather than re-parsing the blob + // every 50 ms through a long render. + const modOn = (k) => ((stCache || st()).mod || {})[k] !== false; // ---- sensitive posts (NIP-36 content warnings, NSFW accounts) ------------- // A post its author marked sensitive carries a content-warning tag — what a // Misskey artist's "sensitive" media becomes on the mostr bridge, and what @@ -11863,7 +11905,13 @@ export function messagesFeature(ctx) { // reconciles the list by post: a new one at the top is inserted as its // own node; the rest keep theirs. const list = visible.slice(0, c.shown || FEED_PAGE); - c.winList = () => c.notes.filter(shownHere).slice(0, c.shown || FEED_PAGE); + // The window's list getter runs on every scroll frame and inside + // holdScroll; filtering every note through the mute/spam/report checks + // each time was the main thread's single largest cost while a feed + // loaded. Anything that changes who is shown goes through render(), which + // lands here again; between renders the same notes give the same list. + const visNotes = c.notes, visShown = c.shown; + c.winList = () => (c.notes === visNotes && c.shown === visShown ? list : c.notes.filter(shownHere).slice(0, c.shown || FEED_PAGE)); const rows = windowedRows(c, list, (ev) => (c.booting && !c.prepared?.has(ev.id) ? keyed(noteRow(ev.pubkey, ev, displayName(ev.pubkey)), ev.id) : feedRow(c, ev))); // Posts that went in above you while you were reading. A floating pill diff --git a/src/features/nostrlogin.js b/src/features/nostrlogin.js index f18b075..f7f9e16 100644 --- a/src/features/nostrlogin.js +++ b/src/features/nostrlogin.js @@ -28,7 +28,13 @@ export function nostrLoginFeature(ctx) { const { h, ui, render, wallet, toast, copyBtn } = ctx; const load = () => wallet.loadFeatureState('nostrlogin', {}); - const save = (st) => wallet.saveFeatureState('nostrlogin', st); + const save = (st) => { idMemo = null; wallet.saveFeatureState('nostrlogin', st); }; + // nostrLoginIdentity() is asked per feed row per moderation check (isMe, + // mePk, trusted…): thousands of times per scroll frame. Each answer parsed + // the stored state twice and bech32-encoded the npub. Keep the last answer + // briefly; a save, a signer change or another wallet's key drops it. + let idMemo = null; + const ID_MEMO_MS = 250; // The signer that opened this session, kept so the names feature can claim // the user's real npub as their payment address (and nominate the wallet @@ -765,10 +771,14 @@ export function nostrLoginFeature(ctx) { // wallet key's face in the gap. // `via`: how the account came in, known before its signer wakes (an // Amber account is one whether or not Amber has been asked anything yet) + const key = wallet.featureStateKey('nostrlogin'); + if (idMemo && idMemo.live === live && idMemo.key === key && Date.now() - idMemo.at < ID_MEMO_MS) return idMemo.value; const st = load(); - if (liveSigner()) return { pubkey: live.pubkey, npub: npubOf(live.pubkey), signer: live, via: st.pubkey === live.pubkey ? reconnectViaOf(st) : viaOf(live) }; - if (!st.pubkey) return null; - return { pubkey: st.pubkey, npub: npubOf(st.pubkey), signer: live, via: reconnectViaOf(st) }; + let value = null; + if (liveSigner()) value = { pubkey: live.pubkey, npub: npubOf(live.pubkey), signer: live, via: st.pubkey === live.pubkey ? reconnectViaOf(st) : viaOf(live) }; + else if (st.pubkey) value = { pubkey: st.pubkey, npub: npubOf(st.pubkey), signer: live, via: reconnectViaOf(st) }; + idMemo = { at: Date.now(), live, key, value }; + return value; }, // A page reload loses the signer. A stored passkey key or an installed // extension reattaches without prompting, which is what lets the payment diff --git a/src/nostr.js b/src/nostr.js index e414d57..b76e865 100644 --- a/src/nostr.js +++ b/src/nostr.js @@ -466,7 +466,16 @@ export function parseNostrPubkey(input) { return null; } // An npub or 64-hex nostr pubkey → hex, or null if it isn't one. -export function npubOf(pkHex) { try { return npubEncode(pkHex); } catch { return null; } } +// Memoized: the feed asks for the reader's npub thousands of times while it +// filters rows, and bech32 encoding was the top self time of a scroll. +const npubMemo = new Map(); +export function npubOf(pkHex) { + if (npubMemo.has(pkHex)) return npubMemo.get(pkHex); + let v = null; try { v = npubEncode(pkHex); } catch {} + if (npubMemo.size > 4000) npubMemo.clear(); + npubMemo.set(pkHex, v); + return v; +} // An event reference other clients can resolve: the id plus who wrote it, so // a quote can be fetched even by someone who doesn't have it yet. export function neventOf(id, author) { try { return neventEncode({ id, author }); } catch { return null; } } diff --git a/tools/feed-scroll-jank.js b/tools/feed-scroll-jank.js new file mode 100644 index 0000000..3877bf3 --- /dev/null +++ b/tools/feed-scroll-jank.js @@ -0,0 +1,222 @@ +// 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 +// +// 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(); +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); } }; +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; +}; +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]); 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.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; } }); + if (feed) R.mo.observe(feed, { childList: true }); + }; + R.stop = () => { + R.live = false; R.lt?.disconnect(); R.et?.disconnect(); R.mo?.disconnect(); + return { t0: R.t0, t1: performance.now(), y0: R.y0, y1: scrollY, frames: R.frames, tasks: R.tasks, wheel: R.wheel, rows: R.rows, + 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'); 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) => { + 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)}`); +} +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) }); +await send('Profiler.start'); +const profT0 = await ev('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 feeds) { + 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 + await ev('window.scrollTo(0,0)'); await sleep(400); + await scenario(`settled ${f}`, { feed: f, dy: delta }); +} +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'); +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 }, null, 1)); + fs.writeFileSync(`${args.out}/run.cpuprofile`, JSON.stringify(profile)); +} +analyze(profile, results, profT0); + +// ---- 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) + `${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 <profile> <fn> for callers; --analyze ${args.out} re-reads them)`); +} |