Add detailed logging for watch history flow

js/nostr.js

@@ -2319,6 +2319,19 @@ class NostrClient {
       relays = Array.from(RELAY_URLS);
     }
 
+    console.info(
+      "[nostr] Preparing to publish watch history snapshot.",
+      {
+        actor: actorKey,
+        snapshotId,
+        itemCount: canonicalItems.length,
+        chunkCount: chunks.length,
+        relaysRequested: relays,
+        attempt: options.attempt || 0,
+        source: options.source || "unknown",
+      }
+    );
+
     const createdAtBase = Math.max(
       Math.floor(Date.now() / 1000),
       this.watchHistoryLastCreatedAt + 1,
@@ -2404,6 +2417,17 @@ class NostrClient {
         return tag;
       });
 
+      console.info(
+        "[nostr] Publishing watch history chunk.",
+        {
+          actor: actorKey,
+          snapshotId,
+          chunkIndex: index,
+          chunkSize: chunkItems.length,
+          relays,
+        }
+      );
+
       const plaintext = JSON.stringify({
         version: 2,
         snapshot: snapshotId,
@@ -2504,6 +2528,15 @@ class NostrClient {
       return { ok: false, error: "signing-failed", retryable: false };
     }
 
+    console.info(
+      "[nostr] Publishing watch history pointer event.",
+      {
+        actor: actorKey,
+        snapshotId,
+        relays,
+      }
+    );
+
     const pointerResults = await publishEventToRelays(
       this.pool,
       relays,
@@ -2588,6 +2621,16 @@ class NostrClient {
       result.error = errorCode;
     }
 
+    console.info("[nostr] Watch history snapshot publish result.", {
+      actor: actorKey,
+      snapshotId,
+      success,
+      partialAcceptance,
+      error: result.error || null,
+      pointerAcceptedCount,
+      chunkAcceptedCounts: chunkResults.map((entry) => entry.acceptedCount),
+    });
+
     return result;
   }
 
@@ -2628,6 +2671,13 @@ class NostrClient {
       canonicalItems,
     );
 
+    console.info("[nostr] Updating watch history list.", {
+      actor: resolvedActor,
+      incomingItemCount: incomingItems.length,
+      finalItemCount: canonicalItems.length,
+      replace: options.replace === true,
+    });
+
     const publishResult = await this.publishWatchHistorySnapshot(
       canonicalItems,
       {
@@ -2637,6 +2687,13 @@ class NostrClient {
       },
     );
 
+    console.info("[nostr] Watch history list publish attempt finished.", {
+      actor: resolvedActor,
+      snapshotId: publishResult.snapshotId || null,
+      success: !!publishResult.ok,
+      retryable: !!publishResult.retryable,
+    });
+
     const metadata = sanitizeWatchHistoryMetadata(cachedEntry.metadata);
     metadata.updatedAt = Date.now();
     metadata.status = publishResult.ok ? "ok" : "error";
@@ -2734,6 +2791,11 @@ class NostrClient {
       return { pointerEvent: null, items: [], snapshotId: "" };
     }
 
+    console.info("[nostr] Fetching watch history from relays.", {
+      actor: resolvedActor,
+      forceRefresh: options.forceRefresh === true,
+    });
+
     const extension = window?.nostr;
 
     const existingEntry = this.watchHistoryCache.get(actorKey);
@@ -2746,6 +2808,11 @@ class NostrClient {
       Number.isFinite(existingEntry.savedAt) &&
       now - existingEntry.savedAt < ttl
     ) {
+      console.info("[nostr] Using cached watch history entry.", {
+        actor: resolvedActor,
+        itemCount: Array.isArray(existingEntry.items) ? existingEntry.items.length : 0,
+        cacheAgeMs: now - existingEntry.savedAt,
+      });
       return {
         pointerEvent: existingEntry.pointerEvent || null,
         items: existingEntry.items || [],
@@ -2754,6 +2821,7 @@ class NostrClient {
     }
 
     if (!this.pool) {
+      console.warn("[nostr] Cannot fetch watch history because relay pool is unavailable. Returning cached values.");
       return {
         pointerEvent: existingEntry?.pointerEvent || null,
         items: existingEntry?.items || [],
@@ -2820,6 +2888,12 @@ class NostrClient {
     }, null);
 
     if (!pointerEvent) {
+      console.info(
+        "[nostr] No watch history pointer event found on relays. Falling back to storage.",
+        {
+          actor: resolvedActor,
+        }
+      );
       const storageEntry = this.getWatchHistoryStorage().actors?.[actorKey];
       const items = Array.isArray(storageEntry?.items)
         ? canonicalizeWatchHistoryItems(storageEntry.items, WATCH_HISTORY_MAX_ITEMS)
@@ -3080,6 +3154,11 @@ class NostrClient {
       return [];
     }
 
+    console.info("[nostr] Resolving watch history for actor.", {
+      actor: resolvedActor,
+      forceRefresh: options.forceRefresh === true,
+    });
+
     const storage = this.getWatchHistoryStorage();
     const fallbackItems = Array.isArray(storage.actors?.[actorKey]?.items)
       ? canonicalizeWatchHistoryItems(
@@ -3123,6 +3202,19 @@ class NostrClient {
       canonicalItems,
     );
 
+    console.info("[nostr] Watch history fetch complete.", {
+      actor: resolvedActor,
+      snapshotId: fetchResult.snapshotId || null,
+      pointerFound: !!fetchResult.pointerEvent,
+      itemCount: canonicalItems.length,
+    });
+
+    console.info("[nostr] Watch history resolved and cached.", {
+      actor: resolvedActor,
+      itemCount: canonicalItems.length,
+      snapshotId: fetchResult.snapshotId || null,
+    });
+
     const entry = {
       actor: resolvedActor,
       items: canonicalItems,

js/watchHistoryService.js

@@ -825,12 +825,25 @@ async function publishView(pointerInput, createdAt, metadata = {}) {
 
   const viewResult = await nostrClient.recordVideoView(pointerInput, recordOptions);
 
+  console.info(
+    "[watchHistoryService] Video view recorded. Preparing watch list update.",
+    {
+      pointer: pointerInput,
+      createdAt,
+      hasMetadata: !!metadata,
+    }
+  );
+
   if (!isFeatureEnabled()) {
     return viewResult;
   }
 
   const pointer = normalizePointerInput(pointerInput);
   if (!pointer) {
+    console.warn(
+      "[watchHistoryService] Skipping watch list update because pointer normalization failed.",
+      { pointerInput }
+    );
     return viewResult;
   }
 
@@ -842,16 +855,28 @@ async function publishView(pointerInput, createdAt, metadata = {}) {
     "";
   const actorKey = normalizeActorKey(actorCandidate);
   if (!actorKey) {
+    console.warn(
+      "[watchHistoryService] Unable to resolve actor for watch list update.",
+      { actorCandidate }
+    );
     return viewResult;
   }
 
   const queue = ensureQueue(actorKey);
   if (!queue) {
+    console.warn(
+      "[watchHistoryService] Failed to resolve queue for actor.",
+      { actorKey }
+    );
     return viewResult;
   }
 
   const normalizedPointer = normalizePointerInput(pointer);
   if (!normalizedPointer) {
+    console.warn(
+      "[watchHistoryService] Pointer normalization failed during queue preparation.",
+      { pointerInput }
+    );
     return viewResult;
   }
 
@@ -860,6 +885,17 @@ async function publishView(pointerInput, createdAt, metadata = {}) {
     viewResult?.event?.created_at
   );
 
+  const key = pointerKey(normalizedPointer);
+  console.info(
+    "[watchHistoryService] Watch list process triggered by video view.",
+    {
+      actor: actorKey,
+      pointerKey: key,
+      watchedAt: normalizedPointer.watchedAt,
+      sessionEvent: normalizedPointer.session === true,
+    }
+  );
+
   const normalizedLogged = normalizeActorKey(nostrClient?.pubkey);
   const normalizedEventActor = normalizeActorKey(
     viewResult?.event?.pubkey || actorCandidate
@@ -868,8 +904,11 @@ async function publishView(pointerInput, createdAt, metadata = {}) {
     normalizedPointer.session = true;
   }
 
-  const key = pointerKey(normalizedPointer);
   if (!key) {
+    console.warn(
+      "[watchHistoryService] Pointer key generation failed. Skipping queue update.",
+      { pointer: normalizedPointer }
+    );
     return viewResult;
   }
 
@@ -896,6 +935,14 @@ async function publishView(pointerInput, createdAt, metadata = {}) {
     queue.throttle.set(key, now);
     persistQueueState();
     notifyQueueChange(actorKey);
+    console.info(
+      "[watchHistoryService] Updated existing watch list entry.",
+      {
+        actor: actorKey,
+        pointerKey: key,
+        watchedAt: existing.pointer.watchedAt,
+      }
+    );
     return viewResult;
   }
 
@@ -918,6 +965,15 @@ async function publishView(pointerInput, createdAt, metadata = {}) {
   persistQueueState();
   notifyQueueChange(actorKey);
 
+  console.info(
+    "[watchHistoryService] Added pointer to pending watch list snapshot queue.",
+    {
+      actor: actorKey,
+      pointerKey: key,
+      queueSize: queue.items.size,
+    }
+  );
+
   return viewResult;
 }
 
@@ -952,6 +1008,16 @@ async function snapshot(items, options = {}) {
 
   const queue = ensureQueue(actorKey);
 
+  console.info(
+    "[watchHistoryService] Initiating watch list snapshot publish.",
+    {
+      actor: actorKey,
+      reason,
+      itemCount: payloadItems.length,
+      queued: queue?.items?.size ?? 0,
+    }
+  );
+
   const run = (async () => {
     emit("snapshot-start", { actor: actorKey, reason, items: payloadItems });
     const publishResult = await nostrClient.publishWatchHistorySnapshot(
@@ -962,6 +1028,17 @@ async function snapshot(items, options = {}) {
       }
     );
 
+    console.info(
+      "[watchHistoryService] Watch list snapshot publish completed.",
+      {
+        actor: actorKey,
+        reason,
+        success: !!publishResult?.ok,
+        snapshotId: publishResult?.snapshotId || null,
+        retryable: !!publishResult?.retryable,
+      }
+    );
+
     if (!publishResult?.ok) {
       if (publishResult?.retryable && publishResult?.snapshotId) {
         if (queue) {
@@ -988,6 +1065,14 @@ async function snapshot(items, options = {}) {
 
     await updateFingerprintCache(actorKey, publishResult.items || payloadItems);
     emit("snapshot-complete", { actor: actorKey, reason, result: publishResult });
+    console.info(
+      "[watchHistoryService] Watch list snapshot processed and fingerprint cache updated.",
+      {
+        actor: actorKey,
+        reason,
+        fingerprintUpdated: true,
+      }
+    );
     return publishResult;
   })()
     .catch((error) => {
@@ -1015,16 +1100,37 @@ async function loadLatest(actorInput) {
 
   const now = Date.now();
   const cacheEntry = state.fingerprintCache.get(actorKey);
+  console.info(
+    "[watchHistoryService] loadLatest invoked.",
+    {
+      actor: actorKey,
+      cacheHasItems: Array.isArray(cacheEntry?.items),
+      cacheExpiresAt: cacheEntry?.expiresAt || null,
+    }
+  );
   if (
     cacheEntry?.items &&
     cacheEntry.expiresAt &&
     cacheEntry.expiresAt > now &&
     Array.isArray(cacheEntry.items)
   ) {
+    console.info(
+      "[watchHistoryService] Returning cached watch list items.",
+      {
+        actor: actorKey,
+        itemCount: cacheEntry.items.length,
+      }
+    );
     return cacheEntry.items;
   }
 
   if (cacheEntry?.promise) {
+    console.info(
+      "[watchHistoryService] Awaiting in-flight watch list refresh.",
+      {
+        actor: actorKey,
+      }
+    );
     return cacheEntry.promise;
   }
 
@@ -1048,6 +1154,13 @@ async function loadLatest(actorInput) {
       }
     });
 
+  console.info(
+    "[watchHistoryService] Triggered nostr watch list refresh.",
+    {
+      actor: actorKey,
+    }
+  );
+
   state.fingerprintCache.set(actorKey, {
     ...(cacheEntry || {}),
     promise,