From 7149255004f52d4050763863071a2e39ddbf63d3 Mon Sep 17 00:00:00 2001 From: thePR0M3TH3AN <53631862+PR0M3TH3AN@users.noreply.github.com> Date: Thu, 2 Oct 2025 09:40:39 -0400 Subject: [PATCH 1/3] Decouple view logging and watch history timers --- docs/watch-history-logging.md | 15 +++++ js/app.js | 109 +++++++++++++++++++++++++--------- js/nostr.js | 29 +++++++++ 3 files changed, 124 insertions(+), 29 deletions(-) create mode 100644 docs/watch-history-logging.md diff --git a/docs/watch-history-logging.md b/docs/watch-history-logging.md new file mode 100644 index 00000000..b5cf1e89 --- /dev/null +++ b/docs/watch-history-logging.md @@ -0,0 +1,15 @@ +# Watch History Logging Cheatsheet + +The watch history publisher emits developer-mode console messages from `publishWatchHistorySnapshot()`. + +- `Watch history snapshot updated` (info) — all chunks and the index event were accepted by at least one relay. The summary includes: + - `actor`: abbreviated pubkey that authored the snapshot. + - `itemCount`: number of watch history entries that made it into the snapshot payload. + - `snapshot`: identifier constructed from the current unix timestamp and a random suffix. + - `latestPointer`: truncated pointer key for the newest watch entry that survived chunking. + - `latestWatchedAt`: ISO timestamp derived from the most recent entry's `watchedAt` (falls back to `Date.now()` when missing). +- `Watch history snapshot publish incomplete` (warning) — at least one chunk or the index event failed to reach any relay. When this fires the snapshot is still cached locally and the client will retry publication later. + +Errors that precede the info log do **not** necessarily indicate a failure. For example, a message like `WebSocket connection to 'ws://127.0.0.1:4869/' failed` simply means one relay in the user's configured relay list is offline. The publisher only requires that at least one relay accepts each chunk before reporting success. + +Refer to the log source in `js/nostr.js` for the exact structure and retry behavior. diff --git a/js/app.js b/js/app.js index 1dcd9332..233a7e6b 100644 --- a/js/app.js +++ b/js/app.js @@ -6983,8 +6983,12 @@ class bitvidApp { return; } - if (state.timerId) { - clearTimeout(state.timerId); + if (state.viewTimerId) { + clearTimeout(state.viewTimerId); + } + + if (state.historyTimerId) { + clearTimeout(state.historyTimerId); } if (Array.isArray(state.handlers) && state.videoEl) { @@ -7080,24 +7084,41 @@ class bitvidApp { return; } - const THRESHOLD_SECONDS = 12; + const VIEW_THRESHOLD_SECONDS = 12; + const WATCH_HISTORY_THRESHOLD_SECONDS = 10; const state = { videoEl, pointer, pointerKey, viewerIdentityKey, handlers: [], - timerId: null, - fired: false, + viewTimerId: null, + historyTimerId: null, + viewFired: false, + historyFired: false, }; - const finalize = () => { - if (state.fired) { + const maybeCleanup = () => { + if (state.viewFired && state.historyFired) { + this.cancelPendingViewLogging(); + } + }; + + const clearTimer = (timerKey) => { + const property = `${timerKey}TimerId`; + if (state[property]) { + clearTimeout(state[property]); + state[property] = null; + } + }; + + const finalizeView = () => { + if (state.viewFired) { return; } - state.fired = true; - cancelTimer(); - this.cancelPendingViewLogging(); + state.viewFired = true; + clearTimer("view"); + maybeCleanup(); const { pointer: thresholdPointer, pointerKey: thresholdPointerKey } = state; @@ -7140,7 +7161,27 @@ class bitvidApp { viewResult ); } + })().catch((error) => { + if (isDevMode) { + console.warn( + "[playVideoWithFallback] Unexpected error while recording video view:", + error + ); + } + }); + }; + const finalizeWatchHistory = () => { + if (state.historyFired) { + return; + } + state.historyFired = true; + clearTimer("history"); + maybeCleanup(); + + const { pointer: thresholdPointer } = state; + + (async () => { try { const historyResult = await updateWatchHistoryList(thresholdPointer); if (!historyResult?.ok && isDevMode) { @@ -7160,22 +7201,17 @@ class bitvidApp { })().catch((error) => { if (isDevMode) { console.warn( - "[playVideoWithFallback] Unexpected error while recording video view:", + "[playVideoWithFallback] Unexpected error while updating watch history:", error ); } }); }; - const cancelTimer = () => { - if (state.timerId) { - clearTimeout(state.timerId); - state.timerId = null; - } - }; - - const scheduleTimer = () => { - if (state.fired) { + const scheduleTimer = (timerKey, thresholdSeconds, callback) => { + const firedKey = `${timerKey}Fired`; + const idKey = `${timerKey}TimerId`; + if (state[firedKey] || state[idKey]) { return; } const currentSeconds = Number.isFinite(videoEl.currentTime) @@ -7183,13 +7219,13 @@ class bitvidApp { : 0; const remainingMs = Math.max( 0, - Math.ceil((THRESHOLD_SECONDS - currentSeconds) * 1000) + Math.ceil((thresholdSeconds - currentSeconds) * 1000) ); if (remainingMs <= 0) { - finalize(); + callback(); return; } - state.timerId = window.setTimeout(finalize, remainingMs); + state[idKey] = window.setTimeout(callback, remainingMs); }; const registerHandler = (eventName, handler) => { @@ -7198,14 +7234,23 @@ class bitvidApp { }; registerHandler("timeupdate", () => { - if (videoEl.currentTime >= THRESHOLD_SECONDS) { - finalize(); + if ( + !state.historyFired && + videoEl.currentTime >= WATCH_HISTORY_THRESHOLD_SECONDS + ) { + finalizeWatchHistory(); + } + if (!state.viewFired && videoEl.currentTime >= VIEW_THRESHOLD_SECONDS) { + finalizeView(); } }); const cancelOnPause = () => { - if (!state.fired) { - cancelTimer(); + if (!state.viewFired) { + clearTimer("view"); + } + if (!state.historyFired) { + clearTimer("history"); } }; @@ -7214,9 +7259,15 @@ class bitvidApp { ); const resumeIfNeeded = () => { - if (!state.fired && !state.timerId) { - scheduleTimer(); + if (state.viewFired && state.historyFired) { + return; } + scheduleTimer( + "history", + WATCH_HISTORY_THRESHOLD_SECONDS, + finalizeWatchHistory + ); + scheduleTimer("view", VIEW_THRESHOLD_SECONDS, finalizeView); }; ["play", "playing"].forEach((event) => diff --git a/js/nostr.js b/js/nostr.js index 70221267..c23c7579 100644 --- a/js/nostr.js +++ b/js/nostr.js @@ -2558,6 +2558,35 @@ class NostrClient { this.scheduleWatchHistoryRepublish(normalizedActor, persistedItems); } + if (isDevMode) { + const latestItem = persistedItems[0] || null; + const latestPointerKey = pointerKey(latestItem); + const latestPointerSummary = latestPointerKey + ? latestPointerKey.length > 32 + ? `${latestPointerKey.slice(0, 32)}…` + : latestPointerKey + : null; + const actorPreview = + normalizedActor.length > 16 + ? `${normalizedActor.slice(0, 8)}…${normalizedActor.slice(-4)}` + : normalizedActor; + const summary = { + actor: actorPreview, + itemCount: persistedItems.length, + snapshot: snapshotId, + latestPointer: latestPointerSummary, + latestWatchedAt: Number.isFinite(latestItem?.watchedAt) + ? new Date(Math.max(0, Math.floor(latestItem.watchedAt))).toISOString() + : null, + }; + + if (overallSuccess) { + console.info("[nostr] Watch history snapshot updated:", summary); + } else { + console.warn("[nostr] Watch history snapshot publish incomplete:", summary); + } + } + const pointerEvent = signedIndexEvent || chunkResults.find((chunk) => chunk.success)?.event || From e97d1bb08446d7634af8b82ae1da6b2e5d544e01 Mon Sep 17 00:00:00 2001 From: thePR0M3TH3AN <53631862+PR0M3TH3AN@users.noreply.github.com> Date: Thu, 2 Oct 2025 09:49:22 -0400 Subject: [PATCH 2/3] Surface watch history publish logs in production --- js/app.js | 12 +++++------- js/nostr.js | 50 ++++++++++++++++++++++++-------------------------- 2 files changed, 29 insertions(+), 33 deletions(-) diff --git a/js/app.js b/js/app.js index 233a7e6b..57b5bd45 100644 --- a/js/app.js +++ b/js/app.js @@ -7184,19 +7184,17 @@ class bitvidApp { (async () => { try { const historyResult = await updateWatchHistoryList(thresholdPointer); - if (!historyResult?.ok && isDevMode) { + if (!historyResult?.ok) { console.warn( "[playVideoWithFallback] Watch history update failed:", historyResult ); } } catch (historyError) { - if (isDevMode) { - console.warn( - "[playVideoWithFallback] Exception while updating watch history:", - historyError - ); - } + console.warn( + "[playVideoWithFallback] Exception while updating watch history:", + historyError + ); } })().catch((error) => { if (isDevMode) { diff --git a/js/nostr.js b/js/nostr.js index c23c7579..0e718499 100644 --- a/js/nostr.js +++ b/js/nostr.js @@ -2558,33 +2558,31 @@ class NostrClient { this.scheduleWatchHistoryRepublish(normalizedActor, persistedItems); } - if (isDevMode) { - const latestItem = persistedItems[0] || null; - const latestPointerKey = pointerKey(latestItem); - const latestPointerSummary = latestPointerKey - ? latestPointerKey.length > 32 - ? `${latestPointerKey.slice(0, 32)}…` - : latestPointerKey - : null; - const actorPreview = - normalizedActor.length > 16 - ? `${normalizedActor.slice(0, 8)}…${normalizedActor.slice(-4)}` - : normalizedActor; - const summary = { - actor: actorPreview, - itemCount: persistedItems.length, - snapshot: snapshotId, - latestPointer: latestPointerSummary, - latestWatchedAt: Number.isFinite(latestItem?.watchedAt) - ? new Date(Math.max(0, Math.floor(latestItem.watchedAt))).toISOString() - : null, - }; + const latestItem = persistedItems[0] || null; + const latestPointerKey = pointerKey(latestItem); + const latestPointerSummary = latestPointerKey + ? latestPointerKey.length > 32 + ? `${latestPointerKey.slice(0, 32)}…` + : latestPointerKey + : null; + const actorPreview = + normalizedActor.length > 16 + ? `${normalizedActor.slice(0, 8)}…${normalizedActor.slice(-4)}` + : normalizedActor; + const summary = { + actor: actorPreview, + itemCount: persistedItems.length, + snapshot: snapshotId, + latestPointer: latestPointerSummary, + latestWatchedAt: Number.isFinite(latestItem?.watchedAt) + ? new Date(Math.max(0, Math.floor(latestItem.watchedAt))).toISOString() + : null, + }; - if (overallSuccess) { - console.info("[nostr] Watch history snapshot updated:", summary); - } else { - console.warn("[nostr] Watch history snapshot publish incomplete:", summary); - } + if (overallSuccess) { + console.info("[nostr] Watch history snapshot updated:", summary); + } else { + console.warn("[nostr] Watch history snapshot publish incomplete:", summary); } const pointerEvent = From 8bdfd672aa549ac6740f23a0500b81fc73452b56 Mon Sep 17 00:00:00 2001 From: thePR0M3TH3AN <53631862+PR0M3TH3AN@users.noreply.github.com> Date: Thu, 2 Oct 2025 10:06:12 -0400 Subject: [PATCH 3/3] Log relay acceptance for watch history publishes --- js/nostr.js | 45 +++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 45 insertions(+) diff --git a/js/nostr.js b/js/nostr.js index 0e718499..d852cf99 100644 --- a/js/nostr.js +++ b/js/nostr.js @@ -2552,6 +2552,51 @@ class NostrClient { overallSuccess = false; } + const publishAttemptSummaries = []; + const acceptedRelaySet = new Set(); + + const recordPublishAttempt = (label, results) => { + if (!Array.isArray(results) || !results.length) { + return; + } + const accepted = results + .filter((result) => result && result.success) + .map((result) => result.url) + .filter((url) => typeof url === "string" && url); + if (accepted.length) { + accepted.forEach((url) => acceptedRelaySet.add(url)); + } + publishAttemptSummaries.push({ label, accepted, results }); + }; + + chunkResults.forEach((chunk) => { + recordPublishAttempt(`chunk#${chunk.chunkIndex}`, chunk.results); + }); + recordPublishAttempt("index", indexPublishResults); + + const failedAttempts = publishAttemptSummaries.filter( + (attempt) => !attempt.accepted.length + ); + + if (acceptedRelaySet.size) { + console.info( + `[nostr] Watch history publish accepted by ${acceptedRelaySet.size} relay(s):`, + Array.from(acceptedRelaySet).join(", ") + ); + } + + if (failedAttempts.length) { + console.warn( + "[nostr] Watch history publish rejected by relays:", + failedAttempts.map((attempt) => ({ + label: attempt.label, + results: attempt.results, + })) + ); + } else if (!acceptedRelaySet.size && publishAttemptSummaries.length) { + console.warn("[nostr] Watch history publish had no relay attempts."); + } + if (overallSuccess) { this.cancelWatchHistoryRepublish(normalizedActor); } else if (allowRetry && persistedItems.length) {