Console: NWC chatter behind a debug switch; dead relays remembered longer and dropped from the pool.

`coinosDebug(true)` in the console (or ?debug=1) turns the nwc: listener
logs back on; they are off by default. Warnings and errors stay.

The red WebSocket lines were the pool's own reconnect loop redialling relays
from other people's relay lists that have been dead for weeks — the sick
list only stopped NEW dials, for ten minutes, and forgot on reload. A dead
relay is now dropped from the pool (no reconnect loop), skipped twice as
long each time it fails (up to a day), keyed by normalized URL, and the
verdict survives a reload. A relay the pool has failed to reconnect to
three times counts as dead.

Co-Authored-By: Claude Fable 5.1 <[email protected]>
Claude-Session: https://claude.ai/code/session_01VhUKyXKtsJ67QAFfb7QR9D

3 files changed, 78 insertions, 25 deletions

diff --git a/src/debug.js b/src/debug.js
new file mode 100644
index 0000000..5d7d085
--- /dev/null
+++ b/src/debug.js
@@ -0,0 +1,17 @@
+// A console kept quiet by default. The chatter that helps when something is
+// being chased (the NWC listener's generations, relay health) goes through
+// dlog and shows only once debugging is switched on — from the console with
+// `coinosDebug(true)`, or by opening the app with `?debug=1`. `coinosDebug(false)`
+// turns it off again. Warnings and errors that mean something is wrong are
+// not gated; they stay on console.warn / console.error.
+const KEY = 'coinos-debug';
+export const debugOn = () => { try { return localStorage.getItem(KEY) === '1'; } catch { return false; } };
+export const dlog = (...a) => { if (debugOn()) console.log(...a); };
+if (typeof window !== 'undefined') {
+  window.coinosDebug = (on = true) => {
+    try { localStorage.setItem(KEY, on ? '1' : '0'); } catch {}
+    console.log('coinos debug ' + (on ? 'on' : 'off'));
+    return on;
+  };
+  try { if (new URLSearchParams(location.search).get('debug') === '1') localStorage.setItem(KEY, '1'); } catch {}
+}
diff --git a/src/features/nwc.js b/src/features/nwc.js
index b72f206..5b95975 100644
--- a/src/features/nwc.js
+++ b/src/features/nwc.js
@@ -27,6 +27,7 @@ import {
   subscribeOn, publishOn, queryOn,
 } from '../nostr.js';
 import { t } from '../i18n.js';
+import { dlog } from '../debug.js';
 import { qrSvg } from '../qr.js';
 import { getNetwork } from '../api.js';
 import { loadBg, saveBg, clearBg } from '../nwc-bg.js';
@@ -287,30 +288,30 @@ export function nwcFeature(ctx) {
   async function onRequest(c, ev) {
     // TEMP instrumentation for the Amethyst-spinner bug: every event that
     // reaches this handler logs, and every silent guard names itself.
-    console.log(`nwc: onRequest ev=${ev.id.slice(0, 8)} kind=${ev.kind} age=${nowSec() - ev.created_at}s from=${ev.pubkey.slice(0, 8)} conn=${c.id}`);
-    if (ev.kind !== REQ_KIND) return console.log('nwc: guard drop — wrong kind');
-    if (handled.has(ev.id)) return console.log('nwc: guard drop — already handled', ev.id.slice(0, 8));
+    dlog(`nwc: onRequest ev=${ev.id.slice(0, 8)} kind=${ev.kind} age=${nowSec() - ev.created_at}s from=${ev.pubkey.slice(0, 8)} conn=${c.id}`);
+    if (ev.kind !== REQ_KIND) return dlog('nwc: guard drop — wrong kind');
+    if (handled.has(ev.id)) return dlog('nwc: guard drop — already handled', ev.id.slice(0, 8));
     handled.add(ev.id);
     if (handled.size > 500) handled.clear();
     if (ev.created_at && nowSec() - ev.created_at > MAX_AGE_SEC) {
-      return console.log('nwc: guard drop — too old', nowSec() - ev.created_at, 's');
+      return dlog('nwc: guard drop — too old', nowSec() - ev.created_at, 's');
     }
     // Same wallet, several tabs: the first to claim the request answers it.
     return withRequestLock(ev.id, () => serve(c, ev),
-      () => console.log('nwc: skip — another tab or the worker holds', ev.id.slice(0, 8)));
+      () => dlog('nwc: skip — another tab or the worker holds', ev.id.slice(0, 8)));
   }
 
   async function serve(c, ev) {
     // only the client this connection was issued to
     if (ev.pubkey !== c.clientPk) {
-      return console.log(`nwc: guard drop — pubkey mismatch got=${ev.pubkey.slice(0, 8)} want=${c.clientPk.slice(0, 8)}`);
+      return dlog(`nwc: guard drop — pubkey mismatch got=${ev.pubkey.slice(0, 8)} want=${c.clientPk.slice(0, 8)}`);
     }
     // Re-resolve the connection from stored state: the closure's `c` is a
     // snapshot from listen() time, so budget math computed from it restarts
     // from a stale value on every request (spends never accumulate), and a
     // connection revoked on another device would keep being served here.
     const cur = (load().conns || []).find((x) => x.id === c.id);
-    if (!cur || cur.revoked) return console.log('nwc: guard drop — connection gone or revoked', c.id);
+    if (!cur || cur.revoked) return dlog('nwc: guard drop — connection gone or revoked', c.id);
     c = cur;
 
     const scheme = ev.tags?.find((x) => x[0] === 'encryption')?.[1] === 'nip44_v2'
@@ -356,13 +357,13 @@ export function nwcFeature(ctx) {
         const prior = await query(NWC_RELAYS, { kinds: [RES_KIND], '#e': [ev.id] }, 1500);
         return !!(prior && prior.length);
       };
-      if (age > 5 && await lookBack()) return console.log('nwc: skip — request already answered elsewhere', ev.id.slice(0, 8));
+      if (age > 5 && await lookBack()) return dlog('nwc: skip — request already answered elsewhere', ev.id.slice(0, 8));
       if (mobile && age <= 5) await new Promise((r) => setTimeout(r, 1000));
       claimed = await claim(ev.id);
-      if (claimed === false) return console.log('nwc: standing down — another device claimed', ev.id.slice(0, 8));
+      if (claimed === false) return dlog('nwc: standing down — another device claimed', ev.id.slice(0, 8));
       if (claimed === null && age <= 5) {
         await new Promise((r) => setTimeout(r, 300 + Math.random() * 900));
-        if (await lookBack()) return console.log('nwc: skip — request already answered elsewhere', ev.id.slice(0, 8));
+        if (await lookBack()) return dlog('nwc: skip — request already answered elsewhere', ev.id.slice(0, 8));
       }
     }
     updateConn(c.id, { lastUsed: Date.now() });
@@ -380,7 +381,7 @@ export function nwcFeature(ctx) {
         await new Promise((r) => setTimeout(r, errGraceMs));
         const prior = await query(NWC_RELAYS, { kinds: [RES_KIND], '#e': [ev.id] }, 1500).catch(() => []);
         if (prior && prior.length) {
-          return console.log('nwc: staying quiet — request answered elsewhere', ev.id.slice(0, 8));
+          return dlog('nwc: staying quiet — request answered elsewhere', ev.id.slice(0, 8));
         }
       }
       delete payload.sibling;
@@ -598,7 +599,7 @@ export function nwcFeature(ctx) {
   const infoPublished = new Set(); // connection ids whose 13194 went out this session
   let listenGen = 0; // TEMP instrumentation: which listen() generation is live
   function stop() {
-    if (unsubs.length) console.log(`nwc: stop() closing ${unsubs.length} sub(s) from gen ${listenGen}`);
+    if (unsubs.length) dlog(`nwc: stop() closing ${unsubs.length} sub(s) from gen ${listenGen}`);
     for (const u of unsubs) { try { u(); } catch {} }
     unsubs = [];
   }
@@ -617,17 +618,17 @@ export function nwcFeature(ctx) {
       ));
     }
     const list = conns();
-    console.log(`nwc: listen() gen ${gen} — ${list.length} connection(s)`);
+    dlog(`nwc: listen() gen ${gen} — ${list.length} connection(s)`);
     for (const c of list) {
-      console.log(`nwc: gen ${gen} subscribing for conn=${c.id} service=${c.servicePk.slice(0, 8)}`);
+      dlog(`nwc: gen ${gen} subscribing for conn=${c.id} service=${c.servicePk.slice(0, 8)}`);
       unsubs.push(subscribe(
         NWC_RELAYS,
         { kinds: [REQ_KIND], '#p': [c.servicePk], since: nowSec() - MAX_AGE_SEC },
         (ev) => {
-          console.log(`nwc: gen ${gen} event arrived ev=${ev.id.slice(0, 8)} for conn=${c.id}`);
+          dlog(`nwc: gen ${gen} event arrived ev=${ev.id.slice(0, 8)} for conn=${c.id}`);
           onRequest(c, ev).catch((e) => console.error('nwc: onRequest threw', e));
         },
-        { onclose: (reasons) => console.log(`nwc: gen ${gen} sub CLOSED for conn=${c.id}:`, JSON.stringify(reasons)) },
+        { onclose: (reasons) => dlog(`nwc: gen ${gen} sub CLOSED for conn=${c.id}:`, JSON.stringify(reasons)) },
       ));
       // Republish the capability event once per session per connection: a
       // client that can't find kind 13194 just spins, and a single publish at
@@ -745,7 +746,7 @@ export function nwcFeature(ctx) {
       await enableBackground();
       await reconcileBg();
       render();
-    } catch (e) { console.log('nwc: background answering not armed:', e.message); }
+    } catch (e) { dlog('nwc: background answering not armed:', e.message); }
   }
 
   // A connection that only answers while a tab happens to be open is a broken
diff --git a/src/nostr.js b/src/nostr.js
index b2d231c..30ddf85 100644
--- a/src/nostr.js
+++ b/src/nostr.js
@@ -17,6 +17,7 @@ import { decode as nip19decode, npubEncode, nsecEncode, neventEncode } from 'nos
 import { normalizeURL } from 'nostr-tools/utils';
 import { wrapEvent as nip17WrapEvent } from 'nostr-tools/nip17';
 import { SimplePool } from 'nostr-tools/pool';
+import { dlog } from './debug.js';
 import { randomBytes, bytesToHex } from '@noble/hashes/utils';
 import { base64urlnopad } from '@scure/base';
 
@@ -107,19 +108,50 @@ export function unwrapDMsOffthread(wraps, sk) {
 // otherwise gets retried on every profile fetch, every sync, every chat
 // subscribe — each attempt logging a browser-level WebSocket error we cannot
 // catch from JS. So we remember failures and stop dialing for a while.
+// A relay found dead is skipped for ten minutes the first time, and twice as
+// long each time it fails again (a day at most), and the verdict survives a
+// reload — a relay that has been gone for weeks (relay.mostr.pub, say, from
+// somebody's relay list) is otherwise redialled at every boot, each attempt
+// a red line in the console.
 const SICK_MS = 10 * 60_000;
-const sick = new Map(); // url -> until
+const SICK_MAX_MS = 24 * 60 * 60_000;
+const SICK_KEY = 'coinos-sick-relays';
+const relayKey = (u) => { try { return normalizeURL(u); } catch { return u; } };
+const sick = new Map(); // normalized url -> { until, n }
+try {
+  const saved = JSON.parse(localStorage.getItem(SICK_KEY) || '{}');
+  for (const [u, v] of Object.entries(saved)) if (v && v.until > Date.now()) sick.set(u, v);
+} catch {}
+const saveSick = () => {
+  try { localStorage.setItem(SICK_KEY, JSON.stringify(Object.fromEntries([...sick].slice(-200)))); } catch {}
+};
 export function markRelaySick(url, why) {
   if (!url) return;
-  if (!sick.has(url)) console.warn(`nostr: ${url} unreachable (${why || 'connect failed'}) — skipping for 10 min`);
-  sick.set(url, Date.now() + SICK_MS);
+  const n = relayKey(url);
+  const prev = sick.get(n);
+  const strikes = prev ? (prev.n || 1) + 1 : 1;
+  const ms = Math.min(SICK_MAX_MS, SICK_MS * 2 ** (strikes - 1));
+  if (!prev) dlog(`nostr: ${url} unreachable (${why || 'connect failed'}) — skipping for ${Math.round(ms / 60_000)} min`);
+  sick.set(n, { until: Date.now() + ms, n: strikes });
+  saveSick();
+  // and out of the pool: left in, its own reconnect loop keeps dialling
+  // (ten seconds, then twenty, then every minute) for as long as the tab lives
+  resetRelay(url);
 }
+const isSick = (u) => sick.has(relayKey(u));
 // Drop known-bad relays, but never hand back an empty set: if everything is
 // sick the network probably is, and one doomed attempt beats doing nothing.
 function liveRelays(list) {
   const now = Date.now();
-  for (const [u, until] of sick) if (until < now) sick.delete(u);
-  const ok = (list || []).filter((u) => !sick.has(u));
+  let changed = false;
+  for (const [u, v] of sick) if (v.until < now) { sick.delete(u); changed = true; }
+  if (changed) saveSick();
+  // a relay the pool has been failing to reconnect to is dead by now
+  for (const u of list || []) {
+    const r = pool.relays.get(relayKey(u));
+    if (r && !r.connected && (r.reconnectAttempts || 0) >= 3) markRelaySick(u, 'reconnect loop');
+  }
+  const ok = (list || []).filter((u) => !isSick(u));
   return ok.length ? ok : (list || []);
 }
 // Dial a relay once in the background to learn whether it's reachable; a
@@ -127,12 +159,13 @@ function liveRelays(list) {
 const probed = new Set();
 function probeRelays(list) {
   for (const url of list || []) {
-    if (probed.has(url) || sick.has(url)) continue;
-    probed.add(url);
+    const n = relayKey(url);
+    if (probed.has(n) || sick.has(n)) continue;
+    probed.add(n);
     Promise.resolve(pool.ensureRelay(url, { connectionTimeout: 6000 }))
       .then(() => {})
       .catch((e) => markRelaySick(url, e && e.message))
-      .finally(() => setTimeout(() => probed.delete(url), SICK_MS));
+      .finally(() => setTimeout(() => probed.delete(n), SICK_MS));
   }
 }
 
@@ -161,6 +194,8 @@ export function resetRelay(url) {
   dialingSince.delete(n);
   const r = pool.relays.get(n);
   if (!r) return;
+  // no zombie: a dropped relay must not go on reconnecting from outside the pool
+  try { r.skipReconnection = true; if (r.reconnectTimeoutHandle) clearTimeout(r.reconnectTimeoutHandle); } catch {}
   try { r.close(); } catch {}
   pool.relays.delete(n);
 }