From 35c4e68cdeb8dda9dd2da650f2b814daca621ac7 Mon Sep 17 00:00:00 2001 From: thePR0M3TH3AN <53631862+PR0M3TH3AN@users.noreply.github.com> Date: Sun, 14 Jun 2026 09:52:41 -0400 Subject: [PATCH] chore(perf): add nip-07/relay diagnostic harnesses + dev REQ monitor MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Headless Playwright probes that reproduce the real login path via a fake window.nostr extension (which loginWithNsec bypasses) and measure steady-state extension-call and relay-REQ rates: - nip07-heat.mjs, req-capture.mjs, ws-lifecycle.mjs, loopc-capture.mjs, etc. Plus js/devReqMonitor.js: a localhost-only WebSocket REQ-rate monitor that warns in-console when relay traffic spikes, naming the storming kinds — used to capture the real-environment storm the mock-relay harness could not see. Removable once the refactor lands. Co-Authored-By: Claude Opus 4.8 --- js/devReqMonitor.js | 69 +++++++++++ js/index.js | 1 + scripts/perf/disclaimer-grid.mjs | 58 +++++++++ scripts/perf/loop-capture-login.mjs | 74 +++++++++++ scripts/perf/loop-capture.mjs | 63 ++++++++++ scripts/perf/loopc-capture.mjs | 25 ++++ scripts/perf/nip07-heat.mjs | 186 ++++++++++++++++++++++++++++ scripts/perf/req-capture.mjs | 85 +++++++++++++ scripts/perf/req-stack-capture.mjs | 60 +++++++++ scripts/perf/ws-lifecycle.mjs | 53 ++++++++ 10 files changed, 674 insertions(+) create mode 100644 js/devReqMonitor.js create mode 100644 scripts/perf/disclaimer-grid.mjs create mode 100644 scripts/perf/loop-capture-login.mjs create mode 100644 scripts/perf/loop-capture.mjs create mode 100644 scripts/perf/loopc-capture.mjs create mode 100644 scripts/perf/nip07-heat.mjs create mode 100644 scripts/perf/req-capture.mjs create mode 100644 scripts/perf/req-stack-capture.mjs create mode 100644 scripts/perf/ws-lifecycle.mjs diff --git a/js/devReqMonitor.js b/js/devReqMonitor.js new file mode 100644 index 00000000..cebcb09f --- /dev/null +++ b/js/devReqMonitor.js @@ -0,0 +1,69 @@ +// Dev-only relay REQ-rate monitor. +// +// Patches WebSocket.send to count outgoing Nostr REQ frames and, every 2s, +// console.warns when the rate exceeds a threshold — naming the storming filter +// kinds. This runs inside the real browser session against real relays/lists, +// which the headless harness cannot fully reproduce. It is purely observational +// and only activates on localhost (or when `localStorage.__bitvidReqMonitor__` +// is set), so production is unaffected. +// +// Remove this import from index.js once the login-perf work is done. + +(function installReqMonitor() { + if (typeof window === "undefined" || typeof WebSocket === "undefined") return; + + const enabled = + location.hostname === "localhost" || + location.hostname === "127.0.0.1" || + (() => { + try { + return localStorage.getItem("__bitvidReqMonitor__") === "1"; + } catch { + return false; + } + })(); + if (!enabled || window.__bitvidReqMonitorInstalled) return; + window.__bitvidReqMonitorInstalled = true; + + const THRESHOLD = 15; // REQ/s above this is a storm worth reporting + const WINDOW_MS = 2000; + let windowReqs = 0; + const byKind = new Map(); + + const origSend = WebSocket.prototype.send; + WebSocket.prototype.send = function (data) { + try { + if (typeof data === "string" && data.startsWith('["REQ"')) { + windowReqs += 1; + const msg = JSON.parse(data); + for (const f of msg.slice(2)) { + const k = Array.isArray(f?.kinds) ? `kind ${f.kinds.join("/")}` : "kind ?"; + byKind.set(k, (byKind.get(k) || 0) + 1); + } + } + } catch { + /* ignore */ + } + return origSend.apply(this, arguments); + }; + + setInterval(() => { + const perSec = (windowReqs / WINDOW_MS) * 1000; + if (perSec >= THRESHOLD) { + const top = [...byKind.entries()] + .sort((a, b) => b[1] - a[1]) + .slice(0, 6) + .map(([k, n]) => `${k}=${n}`) + .join(", "); + // eslint-disable-next-line no-console + console.warn( + `[req-monitor] RELAY STORM ${perSec.toFixed(0)} REQ/s over ${WINDOW_MS / 1000}s → ${top}`, + ); + } + windowReqs = 0; + byKind.clear(); + }, WINDOW_MS); + + // eslint-disable-next-line no-console + console.info("[req-monitor] active — will warn if relay REQ rate spikes."); +})(); diff --git a/js/index.js b/js/index.js index 742a7c69..c0069f4c 100644 --- a/js/index.js +++ b/js/index.js @@ -2,6 +2,7 @@ import { validateInstanceConfig } from "../config/validate-config.js"; import "./bufferPolyfill.js"; +import "./devReqMonitor.js"; // dev-only relay REQ-rate monitor (localhost only) import { getApplication, setApplication, diff --git a/scripts/perf/disclaimer-grid.mjs b/scripts/perf/disclaimer-grid.mjs new file mode 100644 index 00000000..c40725d6 --- /dev/null +++ b/scripts/perf/disclaimer-grid.mjs @@ -0,0 +1,58 @@ +// Reproduces the logged-out "videos don't load until refresh after dismissing +// the disclaimer" bug. Fresh context (no hasSeenDisclaimer), real relays. +// +// Usage: APP=http://localhost:3000 node scripts/perf/disclaimer-grid.mjs + +import { chromium } from "playwright"; + +const APP = process.env.APP || "http://localhost:3000"; + +const cardCount = (page) => + page.evaluate(() => document.querySelectorAll("[data-video-id],[data-video-card]").length); + +const browser = await chromium.launch({ headless: true }); +const ctx = await browser.newContext(); // fresh: no hasSeenDisclaimer +const page = await ctx.newPage(); +const logs = []; +page.on("console", (m) => logs.push(`[${m.type()}] ${m.text()}`.slice(0, 160))); +page.on("pageerror", (e) => logs.push(`[pageerror] ${String(e).split("\n")[0]}`)); + +await page.goto(APP, { waitUntil: "domcontentloaded", timeout: 30000 }); + +// Wait for disclaimer modal to appear. +await page.waitForTimeout(3000); +const hadDisclaimer = await page.evaluate(() => { + const m = document.getElementById("disclaimerModal"); + return !!m && getComputedStyle(m).display !== "none" && m.offsetParent !== null; +}); +const beforeDismiss = await cardCount(page); + +// Dismiss the disclaimer (click its primary/accept button). +let clicked = false; +try { + const btn = page.locator('#disclaimerModal button, [data-testid="disclaimer-accept"]').first(); + if (await btn.count()) { await btn.click({ timeout: 4000 }); clicked = true; } +} catch (_) {} + +await page.waitForTimeout(6000); +const afterDismiss = await cardCount(page); + +// Now reload and re-check (the "refresh fixes it" path). +await page.reload({ waitUntil: "domcontentloaded" }); +await page.waitForTimeout(6000); +const afterReload = await cardCount(page); + +await browser.close(); + +console.log("\n=== DISCLAIMER → GRID ==="); +console.log(`disclaimer shown: ${hadDisclaimer}`); +console.log(`cards before dismiss: ${beforeDismiss}`); +console.log(`dismiss clicked: ${clicked}`); +console.log(`cards after dismiss: ${afterDismiss} <- BUG if 0`); +console.log(`cards after reload: ${afterReload} <- if >0 here but 0 above = the reported bug`); +const interesting = logs.filter((l) => /error|fail|grid|render|feed|disclaimer/i.test(l)); +if (interesting.length) { + console.log("\nrelevant logs:"); + for (const l of interesting.slice(0, 15)) console.log(" " + l); +} +console.log(""); diff --git a/scripts/perf/loop-capture-login.mjs b/scripts/perf/loop-capture-login.mjs new file mode 100644 index 00000000..65a90557 --- /dev/null +++ b/scripts/perf/loop-capture-login.mjs @@ -0,0 +1,74 @@ +// Headless console capture WHILE LOGGED IN via the test harness (nsec). +// Reproduces a structural (data-independent) logged-in CPU loop. +// +// Usage: node scripts/perf/loop-capture-login.mjs [seconds] + +import { chromium } from "playwright"; +import { randomBytes } from "node:crypto"; + +const seconds = Number(process.argv[2] || 12); +const url = "http://localhost:3000/?__test__=1"; +const hexKey = randomBytes(32).toString("hex"); + +const counts = new Map(); +const firstSeen = new Map(); +const pageErrors = []; +const normalize = (t) => + t + .replace(/[0-9a-f]{16,}/gi, "") + .replace(/\b\d{10,}\b/g, "") + .replace(/\b\d+(\.\d+)?ms\b/g, "") + .slice(0, 200); + +const browser = await chromium.launch({ headless: true }); +const page = await (await browser.newContext()).newPage(); +page.on("console", (msg) => { + const text = `${msg.type().toUpperCase()} ${msg.text()}`; + const key = normalize(text); + counts.set(key, (counts.get(key) || 0) + 1); + if (!firstSeen.has(key)) firstSeen.set(key, text); +}); +page.on("pageerror", (e) => pageErrors.push(e.message)); + +await page.goto(url, { waitUntil: "domcontentloaded", timeout: 30000 }); + +// Wait for the harness, then log in with a throwaway key. +let loggedIn = false; +try { + await page.waitForFunction(() => !!window.__bitvidTest__?.loginWithNsec, { + timeout: 15000, + }); + const res = await page.evaluate(async (k) => { + try { + await window.__bitvidTest__.loginWithNsec(k); + return window.__bitvidTest__.getAppState(); + } catch (e) { + return { error: String(e) }; + } + }, hexKey); + loggedIn = !res?.error; + console.log("login result:", JSON.stringify(res)?.slice(0, 300)); +} catch (e) { + console.log("harness/login error:", e.message); +} + +// Reset counters to measure the steady post-login state. +counts.clear(); +firstSeen.clear(); +const start = Date.now(); +await page.waitForTimeout(seconds * 1000); +const elapsed = (Date.now() - start) / 1000; +await browser.close(); + +const sorted = [...counts.entries()].sort((a, b) => b[1] - a[1]); +console.log(`\n=== Logged-in capture (${elapsed.toFixed(1)}s, loggedIn=${loggedIn}) ===`); +console.log(`Distinct lines: ${sorted.length}`); +console.log("TOP REPEATED LINES (count → rate → sample):"); +for (const [key, n] of sorted.slice(0, 18)) { + console.log(` ${String(n).padStart(6)} (${(n / elapsed).toFixed(1)}/s) ${firstSeen.get(key)}`); +} +if (pageErrors.length) { + console.log(`\nPAGE ERRORS (${pageErrors.length}):`); + for (const e of pageErrors.slice(0, 10)) console.log(" ✗ " + e); +} +console.log(""); diff --git a/scripts/perf/loop-capture.mjs b/scripts/perf/loop-capture.mjs new file mode 100644 index 00000000..5b54bc5a --- /dev/null +++ b/scripts/perf/loop-capture.mjs @@ -0,0 +1,63 @@ +// Headless console capture to find a CPU loop in the running dev build. +// Loads localhost:3000, records all console messages for a window, then +// reports the most-repeated messages (the loop) and any page errors. +// +// Usage: node scripts/perf/loop-capture.mjs [url] [seconds] + +import { chromium } from "playwright"; + +const url = process.argv[2] || "http://localhost:3000"; +const seconds = Number(process.argv[3] || 10); + +const counts = new Map(); +const firstSeen = new Map(); +const pageErrors = []; + +function normalize(text) { + // Collapse hashes / ids / timestamps so repeats of the "same" line group. + return text + .replace(/[0-9a-f]{16,}/gi, "") + .replace(/\b\d{10,}\b/g, "") + .replace(/\b\d+(\.\d+)?ms\b/g, "") + .slice(0, 200); +} + +const browser = await chromium.launch({ headless: true }); +const ctx = await browser.newContext(); +const page = await ctx.newPage(); + +page.on("console", (msg) => { + const text = `${msg.type().toUpperCase()} ${msg.text()}`; + const key = normalize(text); + counts.set(key, (counts.get(key) || 0) + 1); + if (!firstSeen.has(key)) firstSeen.set(key, text); +}); +page.on("pageerror", (err) => { + pageErrors.push(err.message); +}); + +const start = Date.now(); +try { + await page.goto(url, { waitUntil: "domcontentloaded", timeout: 30000 }); +} catch (e) { + console.log("goto error:", e.message); +} + +await page.waitForTimeout(seconds * 1000); +const elapsed = (Date.now() - start) / 1000; + +await browser.close(); + +const sorted = [...counts.entries()].sort((a, b) => b[1] - a[1]); +console.log(`\n=== Console capture (${elapsed.toFixed(1)}s @ ${url}) ===`); +console.log(`Total distinct lines: ${sorted.length}\n`); +console.log("TOP REPEATED LINES (count → sample):"); +for (const [key, n] of sorted.slice(0, 15)) { + const rate = (n / elapsed).toFixed(1); + console.log(` ${String(n).padStart(5)} (${rate}/s) ${firstSeen.get(key)}`); +} +if (pageErrors.length) { + console.log(`\nPAGE ERRORS (${pageErrors.length}):`); + for (const e of pageErrors.slice(0, 10)) console.log(" ✗ " + e); +} +console.log(""); diff --git a/scripts/perf/loopc-capture.mjs b/scripts/perf/loopc-capture.mjs new file mode 100644 index 00000000..e99fb4a0 --- /dev/null +++ b/scripts/perf/loopc-capture.mjs @@ -0,0 +1,25 @@ +import { chromium } from "playwright"; +import { randomBytes } from "node:crypto"; + +const seconds = Number(process.argv[2] || 10); +const url = "http://localhost:3000/?__test__=1"; +const hexKey = randomBytes(32).toString("hex"); + +const browser = await chromium.launch({ headless: true }); +const page = await (await browser.newContext()).newPage(); +await page.goto(url, { waitUntil: "domcontentloaded", timeout: 30000 }); +try { + await page.waitForFunction(() => !!window.__bitvidTest__?.loginWithNsec, { timeout: 15000 }); + await page.evaluate((k) => window.__bitvidTest__.loginWithNsec(k), hexKey); +} catch (e) { console.log("login error:", e.message); } + +await page.evaluate(() => { globalThis.__loopc = {}; }); +await page.waitForTimeout(seconds * 1000); +const c = await page.evaluate(() => globalThis.__loopc || {}); +await browser.close(); + +console.log(`\n=== Instrumented call counts (${seconds}s) ===`); +for (const [k, n] of Object.entries(c).sort((a, b) => b[1] - a[1])) { + console.log(` ${String(n).padStart(6)} (${(n / seconds).toFixed(1)}/s) ${k}`); +} +console.log(""); diff --git a/scripts/perf/nip07-heat.mjs b/scripts/perf/nip07-heat.mjs new file mode 100644 index 00000000..5e6a4c18 --- /dev/null +++ b/scripts/perf/nip07-heat.mjs @@ -0,0 +1,186 @@ +// nip-07 login HEAT probe. +// +// Reproduces the *real* nip-07 login path (which loginWithNsec skips) using a +// fake window.nostr extension backed by Node-side nostr-tools crypto, then +// measures STEADY-STATE activity after login settles: +// - extension calls/sec by method (getPublicKey/signEvent/nip04/nip44) +// - outgoing relay REQ frames/sec +// A non-trivial steady-state rate = the login heat (a loop re-decrypting / +// re-subscribing after the feed should be idle). +// +// Usage: APP=http://localhost:3000 WINDOW=15 LATENCY_MS=0 node scripts/perf/nip07-heat.mjs + +import { chromium } from "playwright"; +import { startRelay } from "../agent/simple-relay.mjs"; +import { finalizeEvent, getPublicKey, nip04 } from "nostr-tools"; +import * as nip44 from "nostr-tools/nip44"; + +const APP = process.env.APP || "http://localhost:3000"; +const LATENCY_MS = Number(process.env.LATENCY_MS ?? 0); +const WINDOW = Number(process.env.WINDOW ?? 15); +const VIDEOS = Number(process.env.VIDEOS ?? 30); +const WH_ITEMS = Number(process.env.WH_ITEMS ?? 60); +const WS_PORT = 8973; + +const USER_SK = Uint8Array.from(Buffer.from("11".repeat(32), "hex")); +const USER_PK = getPublicKey(USER_SK); + +let extCalls = {}; +let queue = Promise.resolve(); +const reset = () => { extCalls = {}; }; +function viaExtension(method, fn) { + extCalls[method] = (extCalls[method] || 0) + 1; + const run = async () => { + if (LATENCY_MS > 0) await new Promise((r) => setTimeout(r, LATENCY_MS)); + return fn(); + }; + const p = queue.then(run, run); + queue = p.catch(() => {}); + return p; +} +const convKey = (peerPk) => nip44.v2.utils.getConversationKey(USER_SK, peerPk); + +let reqCount = 0; +let measuring = false; + +async function main() { + const relay = startRelay(WS_PORT, { httpPort: false }); + const relayUrl = `ws://127.0.0.1:${WS_PORT}`; + const now = Math.floor(Date.now() / 1000); + + relay.seedEvent(finalizeEvent({ kind: 10002, created_at: now, tags: [["r", relayUrl]], content: "" }, USER_SK)); + for (let i = 0; i < VIDEOS; i++) { + const dTag = `seed-${i}`; + relay.seedEvent(finalizeEvent({ + kind: 30078, + created_at: now - i * 60, + tags: [["d", dTag], ["t", "video"], ["title", `Heat Video ${i}`], ["url", `https://example.com/v${i}.mp4`]], + content: JSON.stringify({ version: 3, title: `Heat Video ${i}`, videoRootId: dTag, mode: "live", isPrivate: false, deleted: false, url: `https://example.com/v${i}.mp4` }), + }, USER_SK)); + } + + const browser = await chromium.launch({ headless: process.env.HEADLESS !== "0" }); + const context = await browser.newContext(); + + await context.exposeBinding("__extGetPublicKey", () => viaExtension("getPublicKey", () => USER_PK)); + await context.exposeBinding("__extSignEvent", (_s, e) => viaExtension("signEvent", () => finalizeEvent({ ...e, pubkey: USER_PK }, USER_SK))); + await context.exposeBinding("__extNip04Encrypt", (_s, pk, t) => viaExtension("nip04.encrypt", () => nip04.encrypt(USER_SK, pk, t))); + await context.exposeBinding("__extNip04Decrypt", (_s, pk, ct) => viaExtension("nip04.decrypt", () => nip04.decrypt(USER_SK, pk, ct))); + await context.exposeBinding("__extNip44Encrypt", (_s, pk, t) => viaExtension("nip44.encrypt", () => nip44.v2.encrypt(t, convKey(pk)))); + await context.exposeBinding("__extNip44Decrypt", (_s, pk, ct) => viaExtension("nip44.decrypt", () => nip44.v2.decrypt(ct, convKey(pk)))); + + await context.addInitScript((url) => { + localStorage.setItem("hasSeenDisclaimer", "true"); + localStorage.setItem("__bitvidTestMode__", "1"); + localStorage.setItem("__bitvidTestRelays__", JSON.stringify([url])); + window.__bitvidTestRelays__ = [url]; + const w = (n) => (...a) => window[n](...a); + window.nostr = { + getPublicKey: () => w("__extGetPublicKey")(), + signEvent: (e) => w("__extSignEvent")(e), + getRelays: async () => ({}), + nip04: { encrypt: (p, t) => w("__extNip04Encrypt")(p, t), decrypt: (p, c) => w("__extNip04Decrypt")(p, c) }, + nip44: { + encrypt: (p, t) => w("__extNip44Encrypt")(p, t), + decrypt: (p, c) => w("__extNip44Decrypt")(p, c), + v2: { encrypt: (p, t) => w("__extNip44Encrypt")(p, t), decrypt: (p, c) => w("__extNip44Decrypt")(p, c) }, + }, + }; + }, relayUrl); + + const testUrl = `${APP}/?__test__=1&__testRelays__=${encodeURIComponent(relayUrl)}`; + + async function session() { + const page = await context.newPage(); + page.on("websocket", (ws) => { + ws.on("framesent", (d) => { + const p = typeof d.payload === "string" ? d.payload : ""; + if (p.startsWith('["REQ"')) globalThis.__totalReq = (globalThis.__totalReq || 0) + 1; + if (measuring && p.startsWith('["REQ"')) { + reqCount += 1; + try { + const msg = JSON.parse(p); + const sig = msg.slice(2).map((f) => { + const k = f.kinds ? `kinds=${f.kinds.join(",")}` : ""; + const keys = Object.keys(f).filter((x) => x !== "kinds").join(","); + return `${k} ${keys}`.trim(); + }).join(" | "); + globalThis.__reqSig = globalThis.__reqSig || new Map(); + globalThis.__reqSig.set(sig, (globalThis.__reqSig.get(sig) || 0) + 1); + } catch (_) {} + } + }); + }); + await page.goto(testUrl, { waitUntil: "domcontentloaded" }); + await page.waitForFunction(() => typeof window.__bitvidTest__ === "object", { timeout: 20000 }).catch(() => {}); + await page.evaluate((url) => window.__bitvidTest__?.setTestRelays?.([url], { persist: false }), relayUrl).catch(() => {}); + await page.evaluate(() => { + const c = window.__bitvidTest__?.nostrClient; + if (c) c.videoEventVerifier = async (events) => new Set((events || []).map((e) => e && e.id).filter(Boolean)); + }).catch(() => {}); + try { + await page.click('[data-testid="login-button"]', { timeout: 8000 }); + await page.waitForSelector('[data-testid="login-modal"]', { timeout: 8000 }); + const extBtn = page.getByRole("button", { name: /extension|nip-?07|browser/i }).first(); + if (await extBtn.count()) await extBtn.click({ timeout: 5000 }); + else await page.locator('[data-testid="login-provider-button"]').first().click({ timeout: 5000 }); + } catch (_) {} + await page.waitForFunction(async () => (await window.__bitvidTest__?.getAppState?.())?.isLoggedIn === true, { timeout: 15000 }).catch(() => {}); + return page; + } + + // Session 1: log in and publish a watch history (an encrypted list to decrypt). + const s1 = await session(); + if (WH_ITEMS > 0) { + const hex = (i) => (i.toString(16).padStart(8, "0") + "a".repeat(56)).slice(0, 64); + const items = Array.from({ length: WH_ITEMS }, (_, i) => ({ type: "e", value: hex(i + 1), watchedAt: now - i * 30 })); + await s1.evaluate(async (its) => { + const c = window.__bitvidTest__?.nostrClient; + try { await c.publishWatchHistorySnapshot(its, {}); } catch (_) {} + }, items).catch(() => {}); + await s1.waitForTimeout(1500); + } + await s1.close(); + + // Session 2: fresh login, let it settle, then measure STEADY-STATE activity. + globalThis.__totalReq = 0; + const page = await session(); + await page.waitForTimeout(6000); // settle window (initial loads/decrypts) + const burstReq = globalThis.__totalReq || 0; + reset(); + reqCount = 0; + await page.evaluate(() => { globalThis.__loopc = {}; }).catch(() => {}); + measuring = true; + const start = Date.now(); + await page.waitForTimeout(WINDOW * 1000); + const elapsed = (Date.now() - start) / 1000; + measuring = false; + const steady = { ...extCalls }; + const loopc = await page.evaluate(() => globalThis.__loopc || {}).catch(() => ({})); + await page.close(); + console.log("\nInstrumented call counts in window:"); + for (const [k, n] of Object.entries(loopc).sort((a, b) => b[1] - a[1])) console.log(` ${k.padEnd(26)} ${String(n).padStart(6)} (${(n / elapsed).toFixed(1)}/s)`); + + console.log("\n================ NIP-07 LOGIN HEAT ================"); + console.log(`Initial load+settle burst: ${burstReq} REQ frames (first ~6s after login)\n`); + console.log(`Steady-state window: ${elapsed.toFixed(1)}s (post-login-settle)\n`); + console.log("Extension calls in window (method: count → rate):"); + const entries = Object.entries(steady).sort((a, b) => b[1] - a[1]); + if (!entries.length) console.log(" (none — extension idle ✓)"); + for (const [m, n] of entries) console.log(` ${m.padEnd(16)} ${String(n).padStart(5)} (${(n / elapsed).toFixed(1)}/s)`); + const totalExt = entries.reduce((s, [, n]) => s + n, 0); + console.log(`\nTotal extension calls/s: ${(totalExt / elapsed).toFixed(1)}`); + console.log(`Outgoing REQ frames/s : ${(reqCount / elapsed).toFixed(1)}`); + const sigs = [...(globalThis.__reqSig || new Map()).entries()].sort((a, b) => b[1] - a[1]); + console.log("\nTop REQ filters (count → rate → filter):"); + for (const [sig, n] of sigs.slice(0, 10)) console.log(` ${String(n).padStart(5)} (${(n / elapsed).toFixed(1)}/s) ${sig}`); + console.log("\nInterpretation: a healthy idle login should be ~0 ext calls/s."); + console.log("Any steady nip04/nip44.decrypt rate = a re-decrypt loop (the heat)."); + console.log("==================================================\n"); + + await browser.close(); + if (typeof relay.close === "function") await relay.close(); + process.exit(0); +} + +main().catch((e) => { console.error("nip07-heat failed:", e); process.exit(1); }); diff --git a/scripts/perf/req-capture.mjs b/scripts/perf/req-capture.mjs new file mode 100644 index 00000000..9c0c3961 --- /dev/null +++ b/scripts/perf/req-capture.mjs @@ -0,0 +1,85 @@ +// Capture outgoing relay REQ frames while logged in, to identify which +// subscription is storming. Groups REQs by their filter signature. +// +// Usage: node scripts/perf/req-capture.mjs [seconds] + +import { chromium } from "playwright"; +import { randomBytes } from "node:crypto"; + +const seconds = Number(process.argv[2] || 12); +const url = "http://localhost:3000/?__test__=1"; +const hexKey = randomBytes(32).toString("hex"); + +const reqBySig = new Map(); +const sampleBySig = new Map(); +let totalReq = 0; +let closeFrames = 0; + +function filterSig(filters) { + try { + return filters + .map((f) => { + const kinds = f.kinds ? `kinds=${f.kinds.join(",")}` : ""; + const keys = Object.keys(f) + .filter((k) => k !== "kinds") + .map((k) => (Array.isArray(f[k]) ? `${k}[${f[k].length}]` : k)) + .join(","); + return `${kinds} ${keys}`.trim(); + }) + .join(" | "); + } catch { + return "??"; + } +} + +const browser = await chromium.launch({ headless: true }); +const page = await (await browser.newContext()).newPage(); + +page.on("websocket", (ws) => { + ws.on("framesent", (data) => { + const payload = typeof data.payload === "string" ? data.payload : ""; + if (!payload.startsWith("[")) return; + try { + const msg = JSON.parse(payload); + if (msg[0] === "REQ") { + totalReq += 1; + const sig = filterSig(msg.slice(2)); + reqBySig.set(sig, (reqBySig.get(sig) || 0) + 1); + if (!sampleBySig.has(sig)) sampleBySig.set(sig, JSON.stringify(msg.slice(2)).slice(0, 160)); + } else if (msg[0] === "CLOSE") { + closeFrames += 1; + } + } catch {} + }); +}); + +await page.goto(url, { waitUntil: "domcontentloaded", timeout: 30000 }); +try { + await page.waitForFunction(() => !!window.__bitvidTest__?.loginWithNsec, { timeout: 15000 }); + await page.evaluate((k) => window.__bitvidTest__.loginWithNsec(k), hexKey); +} catch (e) { + console.log("login error:", e.message); +} + +// Let the initial feed load + per-video enrichment settle, then measure the +// true steady state (so a one-time load burst isn't mistaken for a loop). +await page.waitForTimeout(8000); +reqBySig.clear(); +sampleBySig.clear(); +totalReq = 0; +closeFrames = 0; +const start = Date.now(); +await page.waitForTimeout(seconds * 1000); +const elapsed = (Date.now() - start) / 1000; +await browser.close(); + +const sorted = [...reqBySig.entries()].sort((a, b) => b[1] - a[1]); +console.log(`\n=== Outgoing REQ capture (${elapsed.toFixed(1)}s) ===`); +console.log(`Total REQ frames: ${totalReq} (${(totalReq / elapsed).toFixed(1)}/s)`); +console.log(`Total CLOSE frames: ${closeFrames} (${(closeFrames / elapsed).toFixed(1)}/s)\n`); +console.log("REQ by filter signature (count → rate → sample):"); +for (const [sig, n] of sorted.slice(0, 15)) { + console.log(` ${String(n).padStart(6)} (${(n / elapsed).toFixed(1)}/s) ${sig}`); + console.log(` e.g. ${sampleBySig.get(sig)}`); +} +console.log(""); diff --git a/scripts/perf/req-stack-capture.mjs b/scripts/perf/req-stack-capture.mjs new file mode 100644 index 00000000..4a5d7f76 --- /dev/null +++ b/scripts/perf/req-stack-capture.mjs @@ -0,0 +1,60 @@ +// Capture the JS call stack at the moment each REQ frame is sent, to pinpoint +// the exact code re-issuing subscriptions in a loop. Overrides WebSocket.send +// via an init script (runs before app code), tags each REQ with a stack, and +// aggregates by stack signature. +// +// Usage: node scripts/perf/req-stack-capture.mjs [seconds] + +import { chromium } from "playwright"; +import { randomBytes } from "node:crypto"; + +const seconds = Number(process.argv[2] || 10); +const url = "http://localhost:3000/?__test__=1"; +const hexKey = randomBytes(32).toString("hex"); + +const browser = await chromium.launch({ headless: true }); +const ctx = await browser.newContext(); + +await ctx.addInitScript(() => { + const origSend = WebSocket.prototype.send; + window.__reqStacks = window.__reqStacks || {}; + WebSocket.prototype.send = function (data) { + try { + if (typeof data === "string" && data.startsWith('["REQ"')) { + const stack = new Error().stack || ""; + // Keep app frames only; drop the wrapper + node_modules noise. + const lines = stack + .split("\n") + .slice(2) + .map((l) => l.trim()) + .filter((l) => l.includes("/js/")) + .map((l) => l.replace(/.*\/js\//, "js/").replace(/:\d+:\d+\)?$/, "")) + .slice(0, 4); + const sig = lines.join(" <- ") || "(no app frames)"; + window.__reqStacks[sig] = (window.__reqStacks[sig] || 0) + 1; + } + } catch {} + return origSend.apply(this, arguments); + }; +}); + +const page = await ctx.newPage(); +await page.goto(url, { waitUntil: "domcontentloaded", timeout: 30000 }); +try { + await page.waitForFunction(() => !!window.__bitvidTest__?.loginWithNsec, { timeout: 15000 }); + await page.evaluate((k) => window.__bitvidTest__.loginWithNsec(k), hexKey); +} catch (e) { + console.log("login error:", e.message); +} + +await page.evaluate(() => { window.__reqStacks = {}; }); +await page.waitForTimeout(seconds * 1000); +const stacks = await page.evaluate(() => window.__reqStacks); +await browser.close(); + +const sorted = Object.entries(stacks).sort((a, b) => b[1] - a[1]); +console.log(`\n=== REQ call-site stacks (${seconds}s) ===\n`); +for (const [sig, n] of sorted.slice(0, 12)) { + console.log(`${String(n).padStart(5)} (${(n / seconds).toFixed(1)}/s)`); + console.log(` ${sig}\n`); +} diff --git a/scripts/perf/ws-lifecycle.mjs b/scripts/perf/ws-lifecycle.mjs new file mode 100644 index 00000000..cdef0a87 --- /dev/null +++ b/scripts/perf/ws-lifecycle.mjs @@ -0,0 +1,53 @@ +// Watch websocket connection lifecycle while logged in: are sockets flapping +// (reconnect storm) or staying open (app-level re-subscription)? +// +// Usage: node scripts/perf/ws-lifecycle.mjs [seconds] + +import { chromium } from "playwright"; +import { randomBytes } from "node:crypto"; + +const seconds = Number(process.argv[2] || 12); +const url = "http://localhost:3000/?__test__=1"; +const hexKey = randomBytes(32).toString("hex"); + +const opensByHost = new Map(); +const closesByHost = new Map(); +let measuring = false; + +const host = (u) => { + try { return new URL(u).host; } catch { return u; } +}; + +const browser = await chromium.launch({ headless: true }); +const page = await (await browser.newContext()).newPage(); + +page.on("websocket", (ws) => { + const h = host(ws.url()); + if (measuring) opensByHost.set(h, (opensByHost.get(h) || 0) + 1); + ws.on("close", () => { + if (measuring) closesByHost.set(h, (closesByHost.get(h) || 0) + 1); + }); +}); + +await page.goto(url, { waitUntil: "domcontentloaded", timeout: 30000 }); +try { + await page.waitForFunction(() => !!window.__bitvidTest__?.loginWithNsec, { timeout: 15000 }); + await page.evaluate((k) => window.__bitvidTest__.loginWithNsec(k), hexKey); +} catch (e) { + console.log("login error:", e.message); +} + +measuring = true; +const start = Date.now(); +await page.waitForTimeout(seconds * 1000); +const elapsed = (Date.now() - start) / 1000; +await browser.close(); + +console.log(`\n=== WebSocket lifecycle (${elapsed.toFixed(1)}s, post-login) ===`); +const hosts = new Set([...opensByHost.keys(), ...closesByHost.keys()]); +for (const h of hosts) { + const o = opensByHost.get(h) || 0; + const c = closesByHost.get(h) || 0; + console.log(` ${h.padEnd(28)} opens=${String(o).padStart(4)} (${(o / elapsed).toFixed(1)}/s) closes=${String(c).padStart(4)} (${(c / elapsed).toFixed(1)}/s)`); +} +console.log("");