Add detailed dev logging for NIP-46 handshake flow

js/nostr.js

@@ -4194,6 +4194,35 @@ async function decryptNip46PayloadWithKeys(privateKey, remotePubkey, ciphertext)
   throw failure;
 }
 
+function summarizeHexForLog(value) {
+  if (typeof value !== "string" || !value.trim()) {
+    return "";
+  }
+
+  const normalized = value.trim().toLowerCase();
+  if (normalized.length <= 12) {
+    return `${normalized} (len:${normalized.length})`;
+  }
+  return `${normalized.slice(0, 8)}…${normalized.slice(-4)} (len:${normalized.length})`;
+}
+
+function summarizeSecretForLog(value) {
+  if (typeof value !== "string" || !value.trim()) {
+    return "<empty>";
+  }
+
+  const trimmed = value.trim();
+  const visible = trimmed.length <= 4 ? "*".repeat(trimmed.length) : `${"*".repeat(3)}…`;
+  return `${visible} (len:${trimmed.length})`;
+}
+
+function summarizeMetadataForLog(metadata) {
+  if (!metadata || typeof metadata !== "object") {
+    return [];
+  }
+  return Object.keys(metadata).slice(0, 12);
+}
+
 async function attemptDecryptNip46HandshakePayload({
   clientPrivateKey,
   candidateRemotePubkeys = [],
@@ -4208,14 +4237,26 @@ async function attemptDecryptNip46HandshakePayload({
       continue;
     }
     seen.add(normalized);
+    devLogger.debug("[nostr] Handshake decrypt attempt", {
+      remotePubkey: summarizeHexForLog(normalized),
+      ciphertextLength: typeof ciphertext === "string" ? ciphertext.length : 0,
+    });
     try {
       const result = await decryptNip46PayloadWithKeys(
         clientPrivateKey,
         normalized,
         ciphertext,
       );
+      devLogger.debug("[nostr] Handshake decrypt succeeded", {
+        remotePubkey: summarizeHexForLog(normalized),
+        algorithm: result?.algorithm || null,
+      });
       return { ...result, remotePubkey: normalized };
     } catch (error) {
+      devLogger.debug("[nostr] Handshake decrypt failed for candidate", {
+        remotePubkey: summarizeHexForLog(normalized),
+        error: error?.message || error,
+      });
       tried.push({ remotePubkey: normalized, error });
     }
   }
@@ -4224,6 +4265,12 @@ async function attemptDecryptNip46HandshakePayload({
     "Failed to decrypt remote signer handshake payload with provided keys.",
   );
   failure.attempts = tried;
+  devLogger.warn("[nostr] Exhausted handshake decrypt candidates", {
+    attempts: tried.map((entry) => ({
+      remotePubkey: summarizeHexForLog(entry.remotePubkey),
+      error: entry.error?.message || entry.error,
+    })),
+  });
   throw failure;
 }
 
@@ -5440,6 +5487,14 @@ export class NostrClient {
     const handshakeSecret =
       typeof secret === "string" && secret.trim() ? secret.trim() : generateNip46Secret();
 
+    devLogger.debug("[nostr] Preparing remote signer handshake", {
+      clientPublicKey: summarizeHexForLog(keyPair.publicKey),
+      relays: resolvedRelays,
+      permissions: requestedPermissions || null,
+      secret: summarizeSecretForLog(handshakeSecret),
+      metadataKeys: summarizeMetadataForLog(sanitizedMetadata),
+    });
+
     const params = [];
     for (const relay of resolvedRelays) {
       params.push(`relay=${encodeURIComponent(relay)}`);
@@ -5457,6 +5512,12 @@ export class NostrClient {
     const query = params.length ? `?${params.join("&")}` : "";
     const uri = `nostrconnect://${keyPair.publicKey}${query}`;
 
+    devLogger.debug("[nostr] Prepared nostrconnect URI", {
+      uri,
+      relayCount: resolvedRelays.length,
+      metadataKeys: summarizeMetadataForLog(sanitizedMetadata),
+    });
+
     return {
       type: "client",
       connectionString: uri,
@@ -5516,6 +5577,14 @@ export class NostrClient {
       throw new Error("No relays available to complete the remote signer handshake.");
     }
 
+    devLogger.debug("[nostr] Waiting for remote signer handshake", {
+      clientPubkey: summarizeHexForLog(normalizedClientPublicKey),
+      relays: resolvedRelays,
+      secret: summarizeSecretForLog(secret),
+      timeoutMs: Number.isFinite(timeoutMs) ? timeoutMs : undefined,
+      expectedRemotePubkey: summarizeHexForLog(expectedRemotePubkey || ""),
+    });
+
     const pool = await this.ensurePool();
     const filters = [
       {
@@ -5590,14 +5659,23 @@ export class NostrClient {
         cleanup();
         const error = new Error("Timed out waiting for the remote signer to acknowledge the connection.");
         error.code = "nip46-handshake-timeout";
+        devLogger.warn("[nostr] Handshake wait timed out", {
+          clientPubkey: summarizeHexForLog(normalizedClientPublicKey),
+          relays: resolvedRelays,
+        });
         reject(error);
       }, waitTimeout);
 
       let subscription;
       try {
         subscription = pool.sub(resolvedRelays, filters);
+        devLogger.debug("[nostr] Handshake subscription established", {
+          relays: resolvedRelays,
+          filters,
+        });
       } catch (error) {
         cleanup();
+        devLogger.warn("[nostr] Failed to subscribe for handshake responses", error);
         reject(error);
         return;
       }
@@ -5608,6 +5686,7 @@ export class NostrClient {
         }
 
         if (!event || event.kind !== NIP46_RPC_KIND) {
+          devLogger.debug("[nostr] Ignoring non-handshake event during wait", event);
           return;
         }
 
@@ -5620,6 +5699,15 @@ export class NostrClient {
           candidateRemotePubkeys.push(eventRemotePubkey);
         }
 
+        devLogger.debug("[nostr] Processing handshake event", {
+          eventId: typeof event.id === "string" ? event.id : "",
+          eventPubkey: summarizeHexForLog(eventRemotePubkey || ""),
+          candidateRemotePubkeys: candidateRemotePubkeys.map((key) =>
+            summarizeHexForLog(key),
+          ),
+          contentLength: typeof event.content === "string" ? event.content.length : 0,
+        });
+
         Promise.resolve()
           .then(() =>
             attemptDecryptNip46HandshakePayload({
@@ -5638,6 +5726,15 @@ export class NostrClient {
               return;
             }
 
+            devLogger.debug("[nostr] Handshake payload parsed", {
+              remotePubkey: summarizeHexForLog(payloadResult?.remotePubkey || ""),
+              eventPubkey: summarizeHexForLog(eventRemotePubkey || ""),
+              algorithm: payloadResult?.algorithm || null,
+              requestId: typeof parsed?.id === "string" ? parsed.id : "",
+              hasResult: parsed?.result !== undefined,
+              hasError: parsed?.error !== undefined,
+            });
+
             const resultValue = coerceStructuredString(parsed?.result);
             const errorValue = coerceStructuredString(parsed?.error);
 
@@ -5690,6 +5787,13 @@ export class NostrClient {
               response: parsed,
               algorithm: normalizeNip46EncryptionAlgorithm(payloadResult?.algorithm),
             });
+
+            devLogger.debug("[nostr] Handshake wait resolved", {
+              remotePubkey: summarizeHexForLog(payloadResult?.remotePubkey || eventRemotePubkey || ""),
+              eventPubkey: summarizeHexForLog(eventRemotePubkey || ""),
+              result: resultValue || null,
+              hasSecret: Boolean(secret),
+            });
           })
           .catch((error) => {
             devLogger.warn("[nostr] Failed to decrypt remote signer handshake payload:", error);
@@ -5728,6 +5832,21 @@ export class NostrClient {
     const overrideMetadata = sanitizeNip46Metadata(providedMetadata);
     const metadata = { ...baseMetadata, ...overrideMetadata };
 
+    devLogger.debug("[nostr] Connecting to remote signer", {
+      connectionType: parsed.type,
+      parsedRemotePubkey: summarizeHexForLog(parsed.remotePubkey || ""),
+      providedClientPublicKey: summarizeHexForLog(providedClientPublicKey),
+      providedClientPrivateKey: summarizeSecretForLog(
+        typeof providedClientPrivateKey === "string" ? providedClientPrivateKey : "",
+      ),
+      providedSecret: summarizeSecretForLog(providedSecret),
+      providedPermissions: providedPermissions || null,
+      handshakeTimeoutMs,
+      parsedRelays: parsed.relays,
+      overrideRelayCount: Array.isArray(providedRelays) ? providedRelays.length : 0,
+      metadataKeys: summarizeMetadataForLog(metadata),
+    });
+
     const handleStatus = (status) => {
       if (typeof onStatus !== "function") {
         return;
@@ -5895,9 +6014,24 @@ export class NostrClient {
       encryption: handshakeAlgorithm,
     });
 
+    devLogger.debug("[nostr] Remote signer RPC client created", {
+      clientPublicKey: summarizeHexForLog(client.clientPublicKey),
+      remotePubkey: summarizeHexForLog(remotePubkey),
+      relays,
+      permissions,
+      secret: summarizeSecretForLog(secret),
+      metadataKeys: summarizeMetadataForLog(metadata),
+      handshakeAlgorithm,
+    });
+
     try {
       await client.ensureSubscription();
 
+      devLogger.debug("[nostr] Remote signer subscription ready", {
+        remotePubkey: summarizeHexForLog(remotePubkey),
+        relayCount: relays.length,
+      });
+
       handleStatus({
         phase: "connect",
         state: "request",
@@ -5909,9 +6043,20 @@ export class NostrClient {
       // Attempt the connect RPC, handling auth challenges when provided.
       for (;;) {
         try {
+          devLogger.debug("[nostr] Sending NIP-46 connect request", {
+            remotePubkey: summarizeHexForLog(remotePubkey),
+            attempt: attempts + 1,
+            permissions: permissions || null,
+          });
           await client.connect({ permissions });
           break;
         } catch (error) {
+          devLogger.warn("[nostr] Connect RPC attempt failed", {
+            remotePubkey: summarizeHexForLog(remotePubkey),
+            attempt: attempts + 1,
+            code: error?.code || null,
+            message: error?.message || String(error),
+          });
           if (error?.code === "auth-challenge" && error.authUrl) {
             attempts += 1;
             handleStatus({
@@ -5937,6 +6082,10 @@ export class NostrClient {
       }
 
       const userPubkey = await client.getUserPubkey();
+      devLogger.debug("[nostr] Retrieved user pubkey from remote signer", {
+        remotePubkey: summarizeHexForLog(remotePubkey),
+        userPubkey: summarizeHexForLog(userPubkey),
+      });
       client.metadata = metadata;
       const signer = this.installNip46Client(client, { userPubkey });
 
@@ -5974,8 +6123,24 @@ export class NostrClient {
         userPubkey,
       });
 
+      devLogger.debug("[nostr] Remote signer connection established", {
+        remotePubkey: summarizeHexForLog(remotePubkey),
+        userPubkey: summarizeHexForLog(userPubkey),
+        relays,
+        permissions: permissions || null,
+        secret: summarizeSecretForLog(secret),
+      });
+
       return { pubkey: userPubkey, signer };
     } catch (error) {
+      devLogger.error("[nostr] Remote signer connection failed", {
+        remotePubkey: summarizeHexForLog(remotePubkey),
+        relays,
+        permissions: permissions || null,
+        secret: summarizeSecretForLog(secret),
+        message: error?.message || String(error),
+        code: error?.code || null,
+      });
       await client.destroy().catch(() => {});
       this.nip46Client = null;
       if (!remember) {

js/services/authProviders/nip46.js

@@ -1,5 +1,35 @@
 import { devLogger } from "../../utils/logger.js";
 
+function summarizeHexForLog(value) {
+  if (typeof value !== "string" || !value.trim()) {
+    return "";
+  }
+
+  const normalized = value.trim().toLowerCase();
+  if (normalized.length <= 12) {
+    return `${normalized} (len:${normalized.length})`;
+  }
+  return `${normalized.slice(0, 8)}…${normalized.slice(-4)} (len:${normalized.length})`;
+}
+
+function summarizeSecretForLog(value) {
+  if (typeof value !== "string" || !value.trim()) {
+    return "<empty>";
+  }
+
+  const trimmed = value.trim();
+  const visible = trimmed.length <= 4 ? "*".repeat(trimmed.length) : `${"*".repeat(3)}…`;
+  return `${visible} (len:${trimmed.length})`;
+}
+
+function sanitizeNip46UriForLog(value) {
+  if (typeof value !== "string" || !value) {
+    return "";
+  }
+
+  return value.replace(/(secret=)([^&#]+)/gi, "$1***");
+}
+
 const PROVIDER_ID = "nip46";
 const PROVIDER_LABEL = "remote signer (nip-46)";
 const PROVIDER_DESCRIPTION =
@@ -112,6 +142,16 @@ export default {
     }
 
     const normalized = normalizeOptions(options);
+
+    devLogger.debug("[nip46] Login requested", {
+      mode: normalized.mode,
+      reuseStored: normalized.reuseStored,
+      remember: normalized.remember,
+      hasConnectionString: Boolean(normalized.connectionString),
+      relayCount: normalized.relays.length,
+      permissions: normalized.permissions || null,
+      secret: summarizeSecretForLog(normalized.secret),
+    });
     let result = null;
 
     if (normalized.reuseStored) {
@@ -120,8 +160,12 @@ export default {
         error.code = "no-stored-session";
         throw error;
       }
+      devLogger.debug("[nip46] Reusing stored remote signer session");
 
       result = await nostrClient.useStoredRemoteSigner();
+      devLogger.debug("[nip46] Stored remote signer returned", {
+        pubkey: summarizeHexForLog(normalizePubkey(result)),
+      });
     } else if (normalized.mode === "manual") {
       const uri = normalized.connectionString;
       if (!uri) {
@@ -130,12 +174,20 @@ export default {
         throw error;
       }
 
+      devLogger.debug("[nip46] Initiating manual remote signer connect", {
+        uri: sanitizeNip46UriForLog(uri),
+        remember: normalized.remember,
+      });
+
       result = await nostrClient.connectRemoteSigner({
         connectionString: uri,
         remember: normalized.remember,
         onAuthUrl: normalized.onAuthUrl,
         onStatus: normalized.onStatus,
       });
+      devLogger.debug("[nip46] Manual connect completed", {
+        pubkey: summarizeHexForLog(normalizePubkey(result)),
+      });
     } else {
       if (normalized.onStatus) {
         try {
@@ -156,6 +208,15 @@ export default {
         permissions: normalized.permissions,
       });
 
+      devLogger.debug("[nip46] Prepared remote signer handshake", {
+        relays: Array.isArray(handshake.relays) ? handshake.relays : [],
+        permissions: handshake.permissions || null,
+        clientPublicKey: summarizeHexForLog(handshake.clientPublicKey),
+        secret: summarizeSecretForLog(handshake.secret),
+        metadataKeys: Object.keys(handshake.metadata || {}),
+        connectionString: sanitizeNip46UriForLog(handshake.connectionString),
+      });
+
       if (normalized.onHandshakePrepared) {
         try {
           normalized.onHandshakePrepared(handshake);
@@ -164,6 +225,12 @@ export default {
         }
       }
 
+      devLogger.debug("[nip46] Connecting to remote signer with prepared handshake", {
+        remember: normalized.remember,
+        handshakeAlgorithm: handshake.algorithm || null,
+        connectionString: sanitizeNip46UriForLog(handshake.connectionString),
+      });
+
       result = await nostrClient.connectRemoteSigner({
         connectionString: handshake.connectionString,
         remember: normalized.remember,
@@ -185,6 +252,11 @@ export default {
 
     const pubkey = normalizePubkey(result);
 
+    devLogger.debug("[nip46] Login finished", {
+      pubkey: summarizeHexForLog(pubkey),
+      hasSigner: Boolean(result && typeof result === "object" && result.signer),
+    });
+
     return {
       authType: PROVIDER_ID,
       pubkey,