From fe976b3ab71fb505c096285eec56b92a52bf8553 Mon Sep 17 00:00:00 2001 From: thePR0M3TH3AN <53631862+PR0M3TH3AN@users.noreply.github.com> Date: Sun, 26 Jul 2026 17:20:52 -0400 Subject: [PATCH] Harden Nostr startup performance --- docs/README.md | 4 + docs/performance-efficiency-plan.md | 31 ++- js/app/authSessionCoordinator.js | 30 +++ js/devReqMonitor.js | 123 ++++++---- js/index.js | 5 + js/performanceHarness.js | 236 ++++++++++++++++++++ js/services/nip71IngestService.js | 71 +++++- js/services/nostrService.js | 78 ++++--- js/webtorrent.js | 36 ++- tests/app/login-defers-dms.test.mjs | 34 +++ tests/dev-req-monitor.test.mjs | 70 ++++++ tests/nip71-ingest-service.test.mjs | 23 ++ tests/nostr/dm-direct-message-flow.test.mjs | 23 +- tests/performance-harness.test.mjs | 91 ++++++++ tests/services/nostr-service.test.mjs | 28 +++ tests/webtorrent-regression.test.mjs | 23 ++ todo/TODO_2026-06-20_pre-launch.md | 15 ++ 17 files changed, 828 insertions(+), 93 deletions(-) create mode 100644 js/performanceHarness.js create mode 100644 tests/dev-req-monitor.test.mjs create mode 100644 tests/performance-harness.test.mjs diff --git a/docs/README.md b/docs/README.md index eccd934b..dd08f31d 100644 --- a/docs/README.md +++ b/docs/README.md @@ -39,6 +39,10 @@ Welcome to the bitvid documentation. This directory contains detailed architectu ## Active plans +- **[Performance & Efficiency Plan](./performance-efficiency-plan.md)**: A + measurement-first staged plan for reducing client CPU, memory, and network + work without degrading Nostr discovery, feed freshness, moderation, or + playback. Tracked as TODO #34. - **[BitUnlock Permission-Layer TODO](../todo/TODO_2026-07-23_bitunlock-permission-layer.md)**: Ordered implementation checklist for the BitUnlock-backed media permission and subscription work. For more details on contributing, please see [CONTRIBUTING.md](../CONTRIBUTING.md). diff --git a/docs/performance-efficiency-plan.md b/docs/performance-efficiency-plan.md index 1abd61dc..5595ab34 100644 --- a/docs/performance-efficiency-plan.md +++ b/docs/performance-efficiency-plan.md @@ -1,6 +1,6 @@ # BitVid Performance & Efficiency Plan -Status: **planned — deeper system audit complete; no performance changes implemented** +Status: **Stage 0 in progress — local-only measurement harness added; no runtime optimization changes implemented** ## Goal @@ -86,12 +86,26 @@ intact. 7. **Measure both wall time and retained state.** A faster task that retains a large worker snapshot, observer target, cache record, or probe client is not an efficiency win. +8. **Preserve discovery boundaries.** A lifecycle or batching optimization must + use the same scoped relay/source selection for historical fetch and live + subscription. Never make a feature appear faster by querying a smaller, + unrelated source set and silently omitting valid user data. + Every affected feature needs a regression fixture containing data available + only through its scoped historical source and data arriving live afterward. ## Measurement harness (Stage 0) Create a local-only, opt-in performance harness. It must be disabled by default and absent from production behavior. +Implemented baseline surface: on `localhost`, `127.0.0.1`, or `::1`, set +`localStorage.__bitvidPerformanceHarness__ = "1"` and reload. The console API +`window.__bitvidPerformance.snapshot()` reports bounded long-task, resource, +navigation, heap (when supported), mark, and manually supplied gauge data. +`mark`, `setGauge`, and `increment` are available for later stage-specific +instrumentation. The harness does not initialize on a public host, even if the +storage key is set. + ### Measurements - Long tasks via `PerformanceObserver`. @@ -115,6 +129,8 @@ default and absent from production behavior. 5. Open hosted playback, then close it. 6. Open torrent-backed playback, then close it. 7. Background the tab for two minutes and restore it. +8. Load an inbox with both legacy NIP-04 and historical NIP-17 conversations, + then receive a live NIP-17 message; verify all conversations are present. ### Stage gate @@ -122,13 +138,14 @@ Record baseline results before any optimization. The harness itself must have a test proving it does not initialize unless its explicit local debug flag is set. -## Stage 1 — Make localhost relay monitoring explicit +## Stage 1 — Make localhost relay monitoring explicit — complete ### Change Change `js/devReqMonitor.js` so it only installs when -`localStorage.__bitvidReqMonitor__ === "1"` (or an equivalent explicit local -debug flag). Do not auto-enable merely because the host is localhost. +`localStorage.__bitvidReqMonitor__ === "1"` on a loopback host. Do not +auto-enable merely because the host is localhost, and never permit the monitor +on a public host. ### Why @@ -143,6 +160,12 @@ local performance testing. - No production host can enable it without the explicit local flag. - Compare idle local CPU/long-task baseline before and after. +Implemented with `isRequestMonitorEnabled()` / `installRequestMonitor()` and +regression coverage for disabled localhost, enabled loopback, and public-host +rejection. To use it during a targeted local relay investigation, set +`localStorage.__bitvidReqMonitor__ = "1"` and reload; remove the key or set it +to any other value for normal profiling. + ### Rollback One isolated commit; restoring the previous activation condition restores the diff --git a/js/app/authSessionCoordinator.js b/js/app/authSessionCoordinator.js index 1c50994d..da8ae650 100644 --- a/js/app/authSessionCoordinator.js +++ b/js/app/authSessionCoordinator.js @@ -176,6 +176,22 @@ export function createAuthSessionCoordinator(deps) { return { async handleAuthLogin(detail = {}) { + const requestedPubkey = + this.normalizeHexPubkey?.(detail?.pubkey || this.pubkey) || + detail?.pubkey || + this.pubkey || + ""; + const inFlightLogin = this._authLoginSync; + if ( + requestedPubkey && + inFlightLogin?.pubkey === requestedPubkey && + inFlightLogin?.promise + ) { + userLogger.info("[auth-login-duplicate-ignored]", { + pubkey: requestedPubkey, + }); + return inFlightLogin.promise; + } const authLoginStart = now(); userLogger.info("[auth-login-start]", { pubkey: detail?.pubkey || this.pubkey || null, @@ -721,6 +737,20 @@ export function createAuthSessionCoordinator(deps) { return listSyncDetail; }); + // A provider/widget can repeat its success event while the first login is + // still hydrating lists. The identity is already active, so replaying the + // full lifecycle only doubles relay work and grid refreshes. Join the + // original lifecycle until its required list sync settles instead. + const authLoginSync = Promise.resolve(listStatePromise).finally(() => { + if (this._authLoginSync?.promise === authLoginSync) { + this._authLoginSync = null; + } + }); + this._authLoginSync = { + pubkey: activePubkey || requestedPubkey, + promise: authLoginSync, + }; + // DMs are intentionally NOT eagerly loaded at login. A cold DM load // (limit: 50) is a burst of nip-07 decrypts that competes with the // feed-driving lists (blocks/subscriptions/hashtags) for the SAME diff --git a/js/devReqMonitor.js b/js/devReqMonitor.js index cebcb09f..b7e123f3 100644 --- a/js/devReqMonitor.js +++ b/js/devReqMonitor.js @@ -1,69 +1,104 @@ -// Dev-only relay REQ-rate monitor. +// Local-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. +// It patches WebSocket.send for a real-session relay-storm investigation, so +// normal localhost development must opt in explicitly. Public deployments can +// never enable it, even if a storage key is present. -(function installReqMonitor() { - if (typeof window === "undefined" || typeof WebSocket === "undefined") return; +export const REQUEST_MONITOR_STORAGE_KEY = "__bitvidReqMonitor__"; - 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 LOCAL_HOSTS = new Set(["localhost", "127.0.0.1", "::1"]); +const THRESHOLD = 15; +const WINDOW_MS = 2000; + +function readStorage(storage) { + try { + return storage?.getItem?.(REQUEST_MONITOR_STORAGE_KEY) ?? null; + } catch (_) { + return null; + } +} + +export function isRequestMonitorEnabled({ locationRef, storage } = {}) { + const hostname = typeof locationRef?.hostname === "string" + ? locationRef.hostname.toLowerCase() + : ""; + return LOCAL_HOSTS.has(hostname) && readStorage(storage) === "1"; +} + +export function installRequestMonitor({ + scope = typeof window !== "undefined" ? window : null, + locationRef = scope?.location, + storage = scope?.localStorage, + WebSocketClass = scope?.WebSocket, + setIntervalFn = scope?.setInterval?.bind(scope), + clearIntervalFn = scope?.clearInterval?.bind(scope), + logger = scope?.console || console, +} = {}) { + if ( + !scope || + !WebSocketClass?.prototype || + typeof WebSocketClass.prototype.send !== "function" || + typeof setIntervalFn !== "function" || + !isRequestMonitorEnabled({ locationRef, storage }) + ) { + return null; + } + if (scope.__bitvidReqMonitorInstalled) { + return scope.__bitvidReqMonitorInstalled; + } - const THRESHOLD = 15; // REQ/s above this is a storm worth reporting - const WINDOW_MS = 2000; let windowReqs = 0; const byKind = new Map(); + const originalSend = WebSocketClass.prototype.send; - const origSend = WebSocket.prototype.send; - WebSocket.prototype.send = function (data) { + WebSocketClass.prototype.send = function monitoredSend(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); + const message = JSON.parse(data); + for (const filter of message.slice(2)) { + const kind = Array.isArray(filter?.kinds) + ? `kind ${filter.kinds.join("/")}` + : "kind ?"; + byKind.set(kind, (byKind.get(kind) || 0) + 1); } } - } catch { - /* ignore */ + } catch (_) { + // Diagnostics must never affect a WebSocket send. } - return origSend.apply(this, arguments); + return originalSend.apply(this, arguments); }; - setInterval(() => { - const perSec = (windowReqs / WINDOW_MS) * 1000; - if (perSec >= THRESHOLD) { + const intervalId = setIntervalFn(() => { + const perSecond = (windowReqs / WINDOW_MS) * 1000; + if (perSecond >= THRESHOLD) { const top = [...byKind.entries()] .sort((a, b) => b[1] - a[1]) .slice(0, 6) - .map(([k, n]) => `${k}=${n}`) + .map(([kind, count]) => `${kind}=${count}`) .join(", "); - // eslint-disable-next-line no-console - console.warn( - `[req-monitor] RELAY STORM ${perSec.toFixed(0)} REQ/s over ${WINDOW_MS / 1000}s → ${top}`, + logger?.warn?.( + `[req-monitor] RELAY STORM ${perSecond.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."); -})(); + const monitor = { + stop() { + WebSocketClass.prototype.send = originalSend; + if (typeof clearIntervalFn === "function") { + clearIntervalFn(intervalId); + } + if (scope.__bitvidReqMonitorInstalled === monitor) { + delete scope.__bitvidReqMonitorInstalled; + } + }, + }; + scope.__bitvidReqMonitorInstalled = monitor; + logger?.info?.("[req-monitor] active — will warn if relay REQ rate spikes."); + return monitor; +} + +installRequestMonitor(); diff --git a/js/index.js b/js/index.js index f63970fe..3ded9298 100644 --- a/js/index.js +++ b/js/index.js @@ -3,6 +3,7 @@ import { validateInstanceConfig } from "../config/validate-config.js"; import "./bufferPolyfill.js"; import "./devReqMonitor.js"; // dev-only relay REQ-rate monitor (localhost only) +import { initPerformanceHarness } from "./performanceHarness.js"; import { getApplication, setApplication, @@ -59,6 +60,10 @@ import { installTestHarness } from "./testHarness.js"; validateInstanceConfig(); +// Local-only, explicit opt-in measurement. This is a no-op in production and +// does not patch application APIs or change scheduling. +initPerformanceHarness(); + // Install test harness early so relay overrides apply before connections. // Only activates when ?__test__=1 or localStorage __bitvidTestMode__ is set. installTestHarness(); diff --git a/js/performanceHarness.js b/js/performanceHarness.js new file mode 100644 index 00000000..6d7682f8 --- /dev/null +++ b/js/performanceHarness.js @@ -0,0 +1,236 @@ +// Local-only performance measurement harness. +// +// This intentionally observes rather than changes application behavior. It is +// available only on a loopback host *and* after an explicit localStorage opt-in, +// so a production visitor cannot accidentally enable it. + +const STORAGE_KEY = "__bitvidPerformanceHarness__"; +const GLOBAL_KEY = "__bitvidPerformance"; +const LOCAL_HOSTS = new Set(["localhost", "127.0.0.1", "::1"]); +const MAX_LONG_TASKS = 200; +const MAX_MARKS = 200; + +function readStorage(storage, key) { + try { + return storage?.getItem?.(key) ?? null; + } catch (_) { + return null; + } +} + +function finiteNumber(value, fallback = 0) { + return Number.isFinite(value) ? Number(value) : fallback; +} + +function normalizeMarkName(name) { + return typeof name === "string" ? name.trim().slice(0, 120) : ""; +} + +export function isLocalPerformanceHarnessEnabled({ + locationRef = typeof location !== "undefined" ? location : null, + storage = typeof localStorage !== "undefined" ? localStorage : null, +} = {}) { + const hostname = typeof locationRef?.hostname === "string" + ? locationRef.hostname.toLowerCase() + : ""; + return LOCAL_HOSTS.has(hostname) && readStorage(storage, STORAGE_KEY) === "1"; +} + +export class PerformanceHarness { + constructor({ scope, performanceRef, PerformanceObserverClass } = {}) { + this.scope = scope || null; + this.performance = performanceRef || this.scope?.performance || null; + this.PerformanceObserverClass = + PerformanceObserverClass || this.scope?.PerformanceObserver || null; + this.startedAt = 0; + this.longTasks = []; + this.marks = []; + this.gauges = new Map(); + this.longTaskObserver = null; + this.started = false; + } + + start() { + if (this.started) { + return this; + } + this.started = true; + this.startedAt = this.now(); + this.observeLongTasks(); + this.mark("harness-start"); + if (this.scope) { + this.scope[GLOBAL_KEY] = this.publicApi(); + } + return this; + } + + stop() { + try { + this.longTaskObserver?.disconnect?.(); + } catch (_) { + // Diagnostics must never affect application teardown. + } + this.longTaskObserver = null; + this.started = false; + if (this.scope?.[GLOBAL_KEY]) { + delete this.scope[GLOBAL_KEY]; + } + } + + now() { + return finiteNumber(this.performance?.now?.(), Date.now()); + } + + observeLongTasks() { + if (typeof this.PerformanceObserverClass !== "function") { + return; + } + try { + const observer = new this.PerformanceObserverClass((list) => { + const entries = list?.getEntries?.() || []; + for (const entry of entries) { + this.recordLongTask(entry); + } + }); + observer.observe({ type: "longtask", buffered: true }); + this.longTaskObserver = observer; + } catch (_) { + // Long Task timing is optional and unsupported in several browsers. + } + } + + recordLongTask(entry) { + const task = { + startTime: finiteNumber(entry?.startTime), + duration: finiteNumber(entry?.duration), + name: typeof entry?.name === "string" ? entry.name : "longtask", + }; + this.longTasks.push(task); + if (this.longTasks.length > MAX_LONG_TASKS) { + this.longTasks.splice(0, this.longTasks.length - MAX_LONG_TASKS); + } + } + + mark(name, detail = {}) { + const normalizedName = normalizeMarkName(name); + if (!normalizedName) { + return false; + } + const entry = { + name: normalizedName, + at: this.now(), + detail: detail && typeof detail === "object" ? { ...detail } : {}, + }; + this.marks.push(entry); + if (this.marks.length > MAX_MARKS) { + this.marks.splice(0, this.marks.length - MAX_MARKS); + } + try { + this.performance?.mark?.(`bitvid:${normalizedName}`); + } catch (_) { + // User Timing is also optional; retain the local mark either way. + } + return true; + } + + setGauge(name, value) { + const normalizedName = normalizeMarkName(name); + if (!normalizedName || !Number.isFinite(value)) { + return false; + } + this.gauges.set(normalizedName, Number(value)); + return true; + } + + increment(name, amount = 1) { + const normalizedName = normalizeMarkName(name); + if (!normalizedName || !Number.isFinite(amount)) { + return false; + } + return this.setGauge(normalizedName, (this.gauges.get(normalizedName) || 0) + amount); + } + + snapshot() { + const resources = this.performance?.getEntriesByType?.("resource") || []; + const navigation = this.performance?.getEntriesByType?.("navigation")?.[0] || null; + const memory = this.performance?.memory; + const longTaskDurationMs = this.longTasks.reduce( + (total, task) => total + finiteNumber(task.duration), + 0, + ); + return { + enabled: this.started, + startedAt: this.startedAt, + elapsedMs: Math.max(0, this.now() - this.startedAt), + longTasks: { + count: this.longTasks.length, + totalDurationMs: longTaskDurationMs, + recent: this.longTasks.slice(-20), + }, + marks: this.marks.slice(-50), + gauges: Object.fromEntries(this.gauges.entries()), + resources: { + count: resources.length, + transferSize: resources.reduce( + (total, entry) => total + finiteNumber(entry?.transferSize), + 0, + ), + }, + navigation: navigation + ? { + domContentLoadedMs: finiteNumber(navigation.domContentLoadedEventEnd), + loadEventMs: finiteNumber(navigation.loadEventEnd), + } + : null, + memory: memory + ? { + usedJsHeapSize: finiteNumber(memory.usedJSHeapSize), + totalJsHeapSize: finiteNumber(memory.totalJSHeapSize), + jsHeapSizeLimit: finiteNumber(memory.jsHeapSizeLimit), + } + : null, + }; + } + + reset() { + this.longTasks.length = 0; + this.marks.length = 0; + this.gauges.clear(); + this.mark("harness-reset"); + } + + publicApi() { + return Object.freeze({ + snapshot: () => this.snapshot(), + mark: (name, detail) => this.mark(name, detail), + setGauge: (name, value) => this.setGauge(name, value), + increment: (name, amount) => this.increment(name, amount), + reset: () => this.reset(), + stop: () => this.stop(), + }); + } +} + +export function initPerformanceHarness({ + scope = typeof window !== "undefined" ? window : null, + locationRef = scope?.location, + storage = scope?.localStorage, + performanceRef = scope?.performance, + PerformanceObserverClass = scope?.PerformanceObserver, +} = {}) { + if (!scope || !isLocalPerformanceHarnessEnabled({ locationRef, storage })) { + return null; + } + if (scope[GLOBAL_KEY]) { + return scope[GLOBAL_KEY]; + } + const harness = new PerformanceHarness({ + scope, + performanceRef, + PerformanceObserverClass, + }); + harness.start(); + return scope[GLOBAL_KEY]; +} + +export const PERFORMANCE_HARNESS_STORAGE_KEY = STORAGE_KEY; diff --git a/js/services/nip71IngestService.js b/js/services/nip71IngestService.js index 16cd4958..dea7194f 100644 --- a/js/services/nip71IngestService.js +++ b/js/services/nip71IngestService.js @@ -41,6 +41,9 @@ const MAX_OPEN_ATTEMPTS = 30; // ~60s of retries // (kind 30000), which during cold-start competes with the initial feed load; a // fallback covers the empty-feed case where no videos:updated ever fires. const FEED_READY_FALLBACK_MS = 12000; +// Some relays do not reliably send EOSE. Do not hold the first visible update +// forever, but give the initial relay burst time to settle before painting it. +const INITIAL_SYNC_FALLBACK_MS = 5000; export function createNip71IngestService({ nostrClient, @@ -54,6 +57,7 @@ export function createNip71IngestService({ maxOpenAttempts = MAX_OPEN_ATTEMPTS, refreshThrottleMs = REFRESH_THROTTLE_MS, feedReadyFallbackMs = FEED_READY_FALLBACK_MS, + initialSyncFallbackMs = INITIAL_SYNC_FALLBACK_MS, } = {}) { let subscription = null; let buffer = []; @@ -67,6 +71,9 @@ export function createNip71IngestService({ let deferArmed = false; let deferTimer = null; let offFeedReady = null; + let initialSyncing = false; + let initialRefreshPending = false; + let initialSyncTimer = null; function isAvailable() { return ( @@ -183,7 +190,13 @@ export function createNip71IngestService({ ); if (injected > 0) { - requestRefresh(); + if (initialSyncing) { + // Keep native BitVid, NIP-71 videos, and future NIP-71 media types in + // the store immediately; defer only the expensive full-feed repaint. + initialRefreshPending = true; + } else { + requestRefresh(); + } } return injected; @@ -211,6 +224,10 @@ export function createNip71IngestService({ function emitRefresh() { lastRefreshAt = Date.now(); + const performanceHarness = globalThis?.__bitvidPerformance; + const performanceRef = globalThis?.performance; + const startedAt = typeof performanceRef?.now === "function" ? performanceRef.now() : 0; + performanceHarness?.mark?.("nip71-refresh-filter-start"); let videos = []; try { videos = @@ -220,6 +237,11 @@ export function createNip71IngestService({ } catch (error) { logger?.warn?.("[nip71Ingest] getFilteredActiveVideos failed", error); } + const filteredAt = typeof performanceRef?.now === "function" ? performanceRef.now() : startedAt; + performanceHarness?.mark?.("nip71-refresh-filter-end", { + durationMs: Math.max(0, filteredAt - startedAt), + videos: videos.length, + }); // Confirm ingested videos survive the feed filter (whitelist/NSFW/etc.). const foreignCount = Array.isArray(videos) ? videos.filter((v) => v?.source === "nip71-ingest").length @@ -234,6 +256,37 @@ export function createNip71IngestService({ reason: "nip71-ingest", }); } + const emittedAt = typeof performanceRef?.now === "function" ? performanceRef.now() : filteredAt; + performanceHarness?.mark?.("nip71-refresh-dispatch-end", { + filterMs: Math.max(0, filteredAt - startedAt), + dispatchMs: Math.max(0, emittedAt - filteredAt), + videos: videos.length, + }); + if (performanceHarness && (filteredAt - startedAt > 50 || emittedAt - filteredAt > 50)) { + userLogger.info( + `[nip71Ingest] refresh timing: filter ${Math.round(filteredAt - startedAt)}ms, dispatch ${Math.round(emittedAt - filteredAt)}ms, videos ${videos.length}`, + ); + } + } + + function finishInitialSync() { + if (!initialSyncing) { + return; + } + if (initialSyncTimer) { + clearTimeout(initialSyncTimer); + initialSyncTimer = null; + } + if (flushTimer) { + clearTimeout(flushTimer); + flushTimer = null; + flush(); + } + initialSyncing = false; + if (initialRefreshPending) { + initialRefreshPending = false; + requestRefresh(); + } } // Defer the first start until the native feed has rendered (first @@ -255,7 +308,7 @@ export function createNip71IngestService({ deferTimer = null; } deferArmed = false; - start(); + start({ coalesceInitialSync: true }); }; if (typeof nostrService?.on === "function") { @@ -265,12 +318,17 @@ export function createNip71IngestService({ return true; } - function start() { + function start({ coalesceInitialSync = false } = {}) { if (started || !isAvailable()) { return false; } started = true; attemptsLeft = maxOpenAttempts; + initialSyncing = coalesceInitialSync; + initialRefreshPending = false; + if (initialSyncing) { + initialSyncTimer = setTimeout(finishInitialSync, initialSyncFallbackMs); + } // Re-subscribe when the whitelist changes so the author scope stays current. if (typeof accessControl?.onWhitelistChange === "function") { @@ -320,6 +378,7 @@ export function createNip71IngestService({ scheduleFlush(); } }, + onEose: finishInitialSync, }); const authorCount = Array.isArray(filters[0]?.authors) ? filters[0].authors.length @@ -348,6 +407,12 @@ export function createNip71IngestService({ clearTimeout(pendingRefreshTimer); pendingRefreshTimer = null; } + if (initialSyncTimer) { + clearTimeout(initialSyncTimer); + initialSyncTimer = null; + } + initialSyncing = false; + initialRefreshPending = false; buffer = []; if (subscription && typeof subscription.close === "function") { try { diff --git a/js/services/nostrService.js b/js/services/nostrService.js index 0fa15f28..5ddfa95d 100644 --- a/js/services/nostrService.js +++ b/js/services/nostrService.js @@ -1071,6 +1071,12 @@ export class NostrService { this.dmActorPubkey = normalizedActor; + const relaySelection = await this.resolveDirectMessageRelaySelection( + normalizedActor, + relays, + ); + const resolvedRelays = relaySelection.relays; + let resolvedSince = Number.isFinite(sinceCandidate) && sinceCandidate >= 0 ? Math.floor(sinceCandidate) @@ -1095,7 +1101,7 @@ export class NostrService { let messages = []; try { messages = await this.nostrClient.listDirectMessages(normalizedActor, { - relays, + relays: resolvedRelays, ...options, limit: resolvedLimit, decryptLimit: resolvedDecryptLimit, @@ -1133,6 +1139,14 @@ export class NostrService { messages: snapshot, actorPubkey: normalizedActor, }); + if (relaySelection.warning === DM_RELAY_WARNING_FALLBACK) { + this.emit("directMessages:relayWarning", { + actorPubkey: normalizedActor, + warning: relaySelection.warning, + relays: resolvedRelays, + source: relaySelection.source, + }); + } this.emit("directMessages:updated", { messages: snapshot, reason: "load", @@ -1156,6 +1170,35 @@ export class NostrService { return snapshot; } + async resolveDirectMessageRelaySelection(actorPubkey, relays = null) { + if (Array.isArray(relays)) { + return { relays, source: "explicit", warning: null }; + } + + const discoveryRelays = Array.isArray(this.nostrClient?.readRelays) + ? this.nostrClient.readRelays + : Array.isArray(this.nostrClient?.relays) + ? this.nostrClient.relays + : []; + + let pool = this.nostrClient?.pool || null; + if (!pool && typeof this.nostrClient?.ensurePool === "function") { + try { + pool = await this.nostrClient.ensurePool(); + } catch (error) { + devLogger.warn("[nostrService] Failed to initialize DM relay pool.", error); + } + } + + return resolveDmRelaySelection({ + pubkey: actorPubkey, + discoveryRelays, + fallbackRelays: discoveryRelays, + pool, + log: { dev: devLogger, user: userLogger }, + }); + } + async ensureDirectMessageSubscription({ actorPubkey, relays, ...handlers } = {}) { const activeActor = actorPubkey || this.resolveActiveDmActor(); const normalizedActor = normalizeHexPubkey(activeActor); @@ -1189,34 +1232,11 @@ export class NostrService { this.stopDirectMessageSubscription(); } - let resolvedRelays = Array.isArray(relays) ? relays : null; - let relaySelection = null; - - if (!resolvedRelays) { - const discoveryRelays = Array.isArray(this.nostrClient?.readRelays) - ? this.nostrClient.readRelays - : Array.isArray(this.nostrClient?.relays) - ? this.nostrClient.relays - : []; - - let pool = this.nostrClient?.pool || null; - if (!pool && typeof this.nostrClient?.ensurePool === "function") { - try { - pool = await this.nostrClient.ensurePool(); - } catch (error) { - devLogger.warn("[nostrService] Failed to initialize DM relay pool.", error); - } - } - - relaySelection = await resolveDmRelaySelection({ - pubkey: normalizedActor, - discoveryRelays, - fallbackRelays: discoveryRelays, - pool, - log: { dev: devLogger, user: userLogger }, - }); - resolvedRelays = relaySelection.relays; - } + const relaySelection = await this.resolveDirectMessageRelaySelection( + normalizedActor, + relays, + ); + const resolvedRelays = relaySelection.relays; try { const subscription = this.nostrClient.subscribeDirectMessages( diff --git a/js/webtorrent.js b/js/webtorrent.js index 6c5ee499..6edb580d 100644 --- a/js/webtorrent.js +++ b/js/webtorrent.js @@ -138,6 +138,29 @@ export class TorrentClient { let timeoutId = null; let pollId = null; + // A successful probe commonly settles from WebTorrent's `wire` event. + // Do not destroy the temporary torrent while that event is still being + // dispatched: WebTorrent continues its handshake bookkeeping after + // listeners return, and synchronous destruction can leave its bitfield + // null (`recalculate(...).fill` in the bundled client). The next task + // guarantees the callback has fully unwound before cleanup. + const disposeProbeTorrent = (target, onDisposed = () => {}) => { + if (!target) { + onDisposed(); + return; + } + const dispose = () => { + try { + target.destroy({ destroyStore: true }); + } catch (err) { + // A completed or already-destroyed probe is harmless. + } finally { + onDisposed(); + } + }; + setTimeout(dispose, 0); + }; + const finalize = (overrides = {}) => { if (settled) { return; @@ -151,14 +174,6 @@ export class TorrentClient { clearInterval(pollId); pollId = null; } - if (torrent) { - try { - torrent.destroy({ destroyStore: true }); - } catch (err) { - // ignore - } - } - const endedAt = typeof performance !== "undefined" && performance?.now ? performance.now() @@ -178,7 +193,10 @@ export class TorrentClient { ...overrides, }; emit("torrent-probe-result", result); - resolve(result); + // Keep the grid-health queue slot occupied until the delayed teardown + // completes. Otherwise the next probe can begin before this probe has + // detached its tracker listeners, briefly exceeding listener limits. + disposeProbeTorrent(torrent, () => resolve(result)); }; try { diff --git a/tests/app/login-defers-dms.test.mjs b/tests/app/login-defers-dms.test.mjs index 68620d15..a6dcc3ce 100644 --- a/tests/app/login-defers-dms.test.mjs +++ b/tests/app/login-defers-dms.test.mjs @@ -178,3 +178,37 @@ test("login reloads the open video comment thread", async () => { assert.deepEqual(loadedVideos, [activeVideo]); }); + +test("duplicate login for the active identity joins the existing list sync", async () => { + const coord = makeCoordinator({ + loadDirectMessages: async () => ({ ok: true }), + refreshUnreadDmIndicator: async () => {}, + }); + let releaseBlocks; + const blocksGate = new Promise((resolve) => { + releaseBlocks = resolve; + }); + let blockLoads = 0; + coord.authService.loadBlocksForPubkey = async () => { + blockLoads += 1; + await blocksGate; + return true; + }; + const detail = { + pubkey: ACTIVE_PUBKEY, + identityChanged: false, + postLogin: { profile: { name: "tester" } }, + postLoginPromise: Promise.resolve({ profile: { name: "tester" } }), + }; + + await coord.handleAuthLogin(detail); + const duplicate = coord.handleAuthLogin({ ...detail }); + for (let attempt = 0; attempt < 20 && blockLoads === 0; attempt += 1) { + await new Promise((resolve) => setTimeout(resolve, 5)); + } + assert.equal(blockLoads, 1, "duplicate login must not start a second list sync"); + + releaseBlocks(); + await duplicate; + assert.equal(coord._authLoginSync, null, "dedupe guard releases after list sync settles"); +}); diff --git a/tests/dev-req-monitor.test.mjs b/tests/dev-req-monitor.test.mjs new file mode 100644 index 00000000..f4f90021 --- /dev/null +++ b/tests/dev-req-monitor.test.mjs @@ -0,0 +1,70 @@ +import test from "node:test"; +import assert from "node:assert/strict"; +import { + installRequestMonitor, + isRequestMonitorEnabled, + REQUEST_MONITOR_STORAGE_KEY, +} from "../js/devReqMonitor.js"; + +function storage(value = null) { + return { getItem: (key) => (key === REQUEST_MONITOR_STORAGE_KEY ? value : null) }; +} + +function createScope({ hostname = "localhost", enabled = false } = {}) { + class FakeWebSocket { + send(data) { + this.sent = data; + return "sent"; + } + } + const intervals = []; + return { + location: { hostname }, + localStorage: storage(enabled ? "1" : null), + WebSocket: FakeWebSocket, + setInterval: (callback, delay) => { + intervals.push({ callback, delay }); + return intervals.length; + }, + clearInterval: () => {}, + console: { info: () => {}, warn: () => {} }, + intervals, + }; +} + +test("request monitor stays disabled on localhost until explicitly enabled", () => { + const scope = createScope(); + const originalSend = scope.WebSocket.prototype.send; + assert.equal(installRequestMonitor({ scope }), null); + assert.equal(scope.WebSocket.prototype.send, originalSend); + assert.equal(scope.intervals.length, 0); +}); + +test("request monitor cannot be enabled on a public host", () => { + assert.equal( + isRequestMonitorEnabled({ + locationRef: { hostname: "unstable.bitvid.network" }, + storage: storage("1"), + }), + false, + ); +}); + +test("explicit loopback opt-in patches REQ sends and can be stopped", () => { + const scope = createScope({ enabled: true }); + const originalSend = scope.WebSocket.prototype.send; + const monitor = installRequestMonitor({ scope }); + + assert.ok(monitor); + assert.notEqual(scope.WebSocket.prototype.send, originalSend); + assert.equal(scope.intervals.length, 1); + assert.equal(scope.intervals[0].delay, 2000); + + const socket = new scope.WebSocket(); + assert.equal(socket.send('["REQ","sub",{"kinds":[1]}]'), "sent"); + assert.equal(socket.sent, '["REQ","sub",{"kinds":[1]}]'); + + monitor.stop(); + assert.equal(scope.WebSocket.prototype.send, originalSend); + assert.equal(scope.__bitvidReqMonitorInstalled, undefined); +}); diff --git a/tests/nip71-ingest-service.test.mjs b/tests/nip71-ingest-service.test.mjs index 5db3c472..eea937aa 100644 --- a/tests/nip71-ingest-service.test.mjs +++ b/tests/nip71-ingest-service.test.mjs @@ -20,6 +20,7 @@ function makeHarness({ whitelistOn = false, whitelist = [] } = {}) { const allEvents = new Map(); let capturedFilters = null; let onEvent = null; + let onEose = null; let closed = false; let whitelistListener = null; @@ -27,6 +28,7 @@ function makeHarness({ whitelistOn = false, whitelist = [] } = {}) { subscribe(opts) { capturedFilters = opts.filters; onEvent = opts.onEvent; + onEose = opts.onEose; return { close() { closed = true; @@ -81,6 +83,7 @@ function makeHarness({ whitelistOn = false, whitelist = [] } = {}) { return closed; }, fireEvent: (e) => onEvent?.(e), + triggerEose: () => onEose?.(), triggerWhitelistChange: () => whitelistListener?.(), triggerFeedReady: () => feedListeners.forEach((fn) => fn({})), nostrClient, @@ -263,6 +266,26 @@ test("startWhenFeedReady falls back to starting if the feed never emits", async svc.stop(); }); +test("initial NIP-71 sync keeps every event but emits one consolidated feed update", () => { + const h = makeHarness(); + const svc = makeService(h, { feedReadyFallbackMs: 100000, initialSyncFallbackMs: 100000 }); + + svc.startWhenFeedReady(); + h.triggerFeedReady(); + h.fireEvent(foreignEvent({ id: "a", kind: 34235, tags: [["d", "ra"], ["title", "A"], ["imeta", "url https://e/a.mp4", "m video/mp4"]] })); + h.fireEvent(foreignEvent({ id: "b", kind: 34235, tags: [["d", "rb"], ["title", "B"], ["imeta", "url https://e/b.mp4", "m video/mp4"]] })); + svc.flush(); + + assert.ok(h.activeMap.has("ROOT:ra") && h.activeMap.has("ROOT:rb"), "all initial NIP-71 events are retained"); + assert.equal(h.emitted.filter((e) => e.name === "videos:updated").length, 0, "no partial-startup repaint"); + + h.triggerEose(); + const refreshes = h.emitted.filter((e) => e.name === "videos:updated"); + assert.equal(refreshes.length, 1, "one consolidated update at initial sync completion"); + assert.equal(refreshes[0].detail.reason, "nip71-ingest"); + svc.stop(); +}); + test("coalesces refresh signals so an event burst can't storm the feed", () => { const h = makeHarness(); const svc = makeService(h, { refreshThrottleMs: 10000 }); diff --git a/tests/nostr/dm-direct-message-flow.test.mjs b/tests/nostr/dm-direct-message-flow.test.mjs index 55d600c0..2e9371c9 100644 --- a/tests/nostr/dm-direct-message-flow.test.mjs +++ b/tests/nostr/dm-direct-message-flow.test.mjs @@ -111,21 +111,36 @@ class FakeRelayPool { } async function configureNostrTools() { - const previousCanonical = globalThis.__BITVID_CANONICAL_NOSTR_TOOLS__; + const previousCanonicalDescriptor = Object.getOwnPropertyDescriptor( + globalThis, + "__BITVID_CANONICAL_NOSTR_TOOLS__", + ); const previousNostrTools = globalThis.NostrTools; const previousReady = globalThis.nostrToolsReady; const nostrTools = await import("nostr-tools"); - globalThis.__BITVID_CANONICAL_NOSTR_TOOLS__ = nostrTools; + // nostrToolsBootstrap deliberately exposes this value as read-only. Test + // setup must replace its *configurable descriptor*, rather than assigning to + // the property and failing after another test/import initialized bootstrap. + Object.defineProperty(globalThis, "__BITVID_CANONICAL_NOSTR_TOOLS__", { + configurable: true, + enumerable: false, + writable: true, + value: nostrTools, + }); globalThis.NostrTools = nostrTools; globalThis.nostrToolsReady = Promise.resolve({ ok: true, value: nostrTools }); const restore = () => { - if (previousCanonical === undefined) { + if (!previousCanonicalDescriptor) { delete globalThis.__BITVID_CANONICAL_NOSTR_TOOLS__; } else { - globalThis.__BITVID_CANONICAL_NOSTR_TOOLS__ = previousCanonical; + Object.defineProperty( + globalThis, + "__BITVID_CANONICAL_NOSTR_TOOLS__", + previousCanonicalDescriptor, + ); } if (previousNostrTools === undefined) { diff --git a/tests/performance-harness.test.mjs b/tests/performance-harness.test.mjs new file mode 100644 index 00000000..3e20a4cb --- /dev/null +++ b/tests/performance-harness.test.mjs @@ -0,0 +1,91 @@ +import test from "node:test"; +import assert from "node:assert/strict"; +import { + initPerformanceHarness, + isLocalPerformanceHarnessEnabled, + PERFORMANCE_HARNESS_STORAGE_KEY, +} from "../js/performanceHarness.js"; + +function createStorage(value = null) { + return { getItem: (key) => (key === PERFORMANCE_HARNESS_STORAGE_KEY ? value : null) }; +} + +function createPerformance() { + const marks = []; + return { + now: () => 100, + mark: (name) => marks.push(name), + getEntriesByType: (type) => { + if (type === "resource") { + return [{ transferSize: 12 }, { transferSize: 30 }]; + } + if (type === "navigation") { + return [{ domContentLoadedEventEnd: 12, loadEventEnd: 24 }]; + } + return []; + }, + memory: { usedJSHeapSize: 10, totalJSHeapSize: 20, jsHeapSizeLimit: 30 }, + marks, + }; +} + +test("performance harness stays absent without explicit loopback opt-in", () => { + const scope = { + location: { hostname: "localhost" }, + localStorage: createStorage(), + performance: createPerformance(), + }; + + assert.equal(isLocalPerformanceHarnessEnabled({ + locationRef: scope.location, + storage: scope.localStorage, + }), false); + assert.equal(initPerformanceHarness({ scope }), null); + assert.equal(scope.__bitvidPerformance, undefined); +}); + +test("performance harness cannot be enabled on a non-loopback host", () => { + assert.equal(isLocalPerformanceHarnessEnabled({ + locationRef: { hostname: "unstable.bitvid.network" }, + storage: createStorage("1"), + }), false); +}); + +test("explicit loopback opt-in exposes bounded local measurements", () => { + let observerCallback = null; + class FakePerformanceObserver { + constructor(callback) { + observerCallback = callback; + } + observe() {} + disconnect() {} + } + const scope = { + location: { hostname: "127.0.0.1" }, + localStorage: createStorage("1"), + performance: createPerformance(), + PerformanceObserver: FakePerformanceObserver, + }; + + const api = initPerformanceHarness({ scope }); + assert.equal(typeof api?.snapshot, "function"); + assert.equal(scope.__bitvidPerformance, api); + + observerCallback({ + getEntries: () => [{ name: "longtask", startTime: 3, duration: 51 }], + }); + api.mark("feed-refresh", { feed: "for-you" }); + api.setGauge("active-workers", 1); + api.increment("active-workers"); + + const snapshot = api.snapshot(); + assert.equal(snapshot.longTasks.count, 1); + assert.equal(snapshot.longTasks.totalDurationMs, 51); + assert.equal(snapshot.resources.transferSize, 42); + assert.equal(snapshot.gauges["active-workers"], 2); + assert.equal(snapshot.memory.usedJsHeapSize, 10); + assert.ok(snapshot.marks.some((entry) => entry.name === "feed-refresh")); + + api.stop(); + assert.equal(scope.__bitvidPerformance, undefined); +}); diff --git a/tests/services/nostr-service.test.mjs b/tests/services/nostr-service.test.mjs index f47ce03a..5f225c3d 100644 --- a/tests/services/nostr-service.test.mjs +++ b/tests/services/nostr-service.test.mjs @@ -9,6 +9,8 @@ describe("NostrService", () => { // Reset state nostrService.videosMap = new Map(); nostrService.dmMessages = []; + nostrService.dmMessageIndex = new Map(); + nostrService.dmActorPubkey = null; // Mock the internal nostrClient mockClient = { @@ -145,4 +147,30 @@ describe("NostrService", () => { assert.equal(nostrService.dmMessageIndex.size, 0); }); }); + + describe("loadDirectMessages", () => { + it("uses the actor NIP-17 relay list for the initial historical inbox fetch", async () => { + const actor = "a".repeat(64); + const dmRelay = "wss://dm-relay.example.com"; + mockClient.readRelays = ["wss://discovery.example.com"]; + mockClient.pool.list.mock.mockImplementation(async () => [ + { + pubkey: actor, + created_at: 10, + tags: [["relay", dmRelay]], + }, + ]); + mockClient.listDirectMessages = mock.fn(async () => []); + + await nostrService.loadDirectMessages({ actorPubkey: actor, initialLoad: true }); + + assert.equal(mockClient.listDirectMessages.mock.callCount(), 1); + const [, options] = mockClient.listDirectMessages.mock.calls[0].arguments; + assert.deepEqual( + options.relays, + [dmRelay], + "historical NIP-17 messages must use the same relay list as the live subscription", + ); + }); + }); }); diff --git a/tests/webtorrent-regression.test.mjs b/tests/webtorrent-regression.test.mjs index 3683a355..54d11b0e 100644 --- a/tests/webtorrent-regression.test.mjs +++ b/tests/webtorrent-regression.test.mjs @@ -57,8 +57,17 @@ class MockTorrent extends EventEmitter { } destroy(opts, cb) { + this.destroyed = true; + this.destroyedDuringWire = this.emittingWire === true; if (typeof cb === 'function') cb(); } + + emit(eventName, ...args) { + if (eventName === 'wire') this.emittingWire = true; + const result = super.emit(eventName, ...args); + if (eventName === 'wire') this.emittingWire = false; + return result; + } } describe("WebTorrent Regression Tests", () => { @@ -118,4 +127,18 @@ describe("WebTorrent Regression Tests", () => { assert.strictEqual(result.healthy, false, "Should be unhealthy"); assert.strictEqual(result.reason, "timeout", "Reason should be 'timeout'"); }); + + it("defers probe cleanup until after a successful wire callback returns", async () => { + const client = new TorrentClient({ webTorrentClass: MockWebTorrent }); + const magnet = "magnet:?xt=urn:btih:0123456789abcdef0123456789abcdef01234567"; + const result = await client.probePeers(magnet, { + timeoutMs: 1000, + urlList: ["http://localhost:8080/video.mp4"], + }); + const torrent = client.probeClient.torrents[0]; + + assert.equal(result.healthy, true); + assert.equal(torrent.destroyed, true, "temporary probe torrent is cleaned up before its queue slot releases"); + assert.equal(torrent.destroyedDuringWire, false, "probe cleanup is not synchronous with the wire event"); + }); }); diff --git a/todo/TODO_2026-06-20_pre-launch.md b/todo/TODO_2026-06-20_pre-launch.md index d0154955..fd6af11e 100644 --- a/todo/TODO_2026-06-20_pre-launch.md +++ b/todo/TODO_2026-06-20_pre-launch.md @@ -30,6 +30,21 @@ tests → `npm run build` + `npm run test:unit` green → commit + push. ## Open — high priority (launch-blocking candidates) +### 34. Performance and efficiency — staged, measurement-first plan + +- [x] Establish the local-only measurement harness (`js/performanceHarness.js`) + and capture the agreed baseline before changing runtime behavior. Enable + only on loopback with `localStorage.__bitvidPerformanceHarness__ = "1"`. +- [ ] Then implement and independently verify the staged lifecycle work: + ~~explicit localhost relay diagnostics~~ (complete), lazy/coalesced Explore and For You + indexing, cancellable source-health probes, bounded event-cache growth, + service-worker/image-cache cadence, and only then measured visual/bundle + loading improvements. +- **Plan and acceptance criteria:** + [`docs/performance-efficiency-plan.md`](../docs/performance-efficiency-plan.md). + Preserve live Nostr ingestion, feed freshness, source fallback, WebTorrent + playback, moderation decisions, and recommendation inputs at every stage. + ### 33. Login / profile / session persistence broken with NIP-46 (Amber) — AUDIT (BUG) Reported 2026-06-25. All symptoms observed with a **NIP-46 remote signer (Amber)**. Likely a shared root cause in session/identity persistence + multi-account handling.