diff --git a/js/nostr.js b/js/nostr.js index 0d555ccb..4a8d0566 100644 --- a/js/nostr.js +++ b/js/nostr.js @@ -4223,6 +4223,132 @@ function summarizeMetadataForLog(metadata) { return Object.keys(metadata).slice(0, 12); } +function summarizeUrlForLog(value) { + if (typeof value !== "string" || !value.trim()) { + return ""; + } + + const trimmed = value.trim(); + try { + const url = new URL(trimmed); + return { + origin: url.origin, + pathname: url.pathname, + hasQuery: Boolean(url.search), + hasHash: Boolean(url.hash), + length: trimmed.length, + }; + } catch (error) { + const length = trimmed.length; + if (length <= 64) { + return `${trimmed} (len:${length})`; + } + return `${trimmed.slice(0, 32)}…${trimmed.slice(-8)} (len:${length})`; + } +} + +function summarizePayloadPreviewForLog(value) { + if (typeof value !== "string") { + return { type: typeof value }; + } + + const trimmed = value.trim(); + if (!trimmed) { + return { type: "string", length: 0 }; + } + + return { + type: "string", + length: trimmed.length, + preview: trimmed.length <= 96 ? trimmed : `${trimmed.slice(0, 64)}…`, + }; +} + +function summarizeRpcParamsForLog(method, params) { + if (!Array.isArray(params)) { + return []; + } + + return params.map((param, index) => { + if (typeof param === "string") { + if (method === "connect" && index === 1) { + return { index, secret: summarizeSecretForLog(param) }; + } + const trimmed = param.trim(); + if (!trimmed) { + return { index, type: "string", length: 0 }; + } + if (method === "sign_event") { + return { index, type: "string", length: trimmed.length }; + } + if (trimmed.length <= 64) { + return { index, value: trimmed, length: trimmed.length }; + } + return { + index, + type: "string", + length: trimmed.length, + preview: `${trimmed.slice(0, 32)}…${trimmed.slice(-8)}`, + }; + } + + if (param && typeof param === "object") { + return { + index, + type: Array.isArray(param) ? "array" : "object", + keys: Object.keys(param).slice(0, 6), + }; + } + + return { index, type: typeof param }; + }); +} + +function summarizeRpcResultForLog(method, result) { + if (typeof result === "string") { + const trimmed = result.trim(); + if (!trimmed) { + return { type: "string", length: 0 }; + } + if (method === "connect") { + return { type: "string", length: trimmed.length, secret: summarizeSecretForLog(trimmed) }; + } + if (trimmed.length <= 96) { + return { type: "string", length: trimmed.length, value: trimmed }; + } + return { + type: "string", + length: trimmed.length, + preview: `${trimmed.slice(0, 48)}…${trimmed.slice(-12)}`, + }; + } + + if (!result) { + return { type: typeof result }; + } + + if (typeof result === "object") { + return { + type: Array.isArray(result) ? "array" : "object", + keys: Object.keys(result).slice(0, 6), + }; + } + + return { type: typeof result }; +} + +function summarizeRelayPublishResultsForLog(results) { + if (!Array.isArray(results)) { + return []; + } + + return results.map((entry) => ({ + relay: entry?.relay || "", + success: Boolean(entry?.ok), + reason: entry?.error ? entry.error?.message || String(entry.error) : null, + })); +} + async function attemptDecryptNip46HandshakePayload({ clientPrivateKey, candidateRemotePubkeys = [], @@ -4334,6 +4460,7 @@ class Nip46RpcClient { async ensurePool() { if (this.pool) { + devLogger.debug("[nostr] Remote signer using existing nostr pool"); return this.pool; } @@ -4342,11 +4469,16 @@ class Nip46RpcClient { } await this.nostrClient.ensurePool(); + devLogger.debug("[nostr] Remote signer pool ensured"); return this.pool; } async ensureCipher() { if (this.cipher) { + devLogger.debug("[nostr] Reusing cached remote signer cipher", { + remotePubkey: summarizeHexForLog(this.remotePubkey), + algorithm: this.cipher?.algorithm || this.encryptionAlgorithm || null, + }); return this.cipher; } @@ -4365,22 +4497,57 @@ class Nip46RpcClient { if (!this.encryptionAlgorithm && cipher?.algorithm) { this.encryptionAlgorithm = cipher.algorithm; } + devLogger.debug("[nostr] Created remote signer cipher", { + remotePubkey: summarizeHexForLog(this.remotePubkey), + algorithm: cipher?.algorithm || null, + }); return this.cipher; } - async encryptPayload(payload) { + async encryptPayload(payload, context = {}) { const { encrypt } = await this.ensureCipher(); const serialized = typeof payload === "string" ? payload : JSON.stringify(payload); - return encrypt(serialized); + const ciphertext = encrypt(serialized); + devLogger.debug("[nostr] Encrypted remote signer payload", { + remotePubkey: summarizeHexForLog(this.remotePubkey), + method: context.method || null, + requestId: context.requestId || null, + payloadPreview: summarizePayloadPreviewForLog(serialized), + ciphertextLength: typeof ciphertext === "string" ? ciphertext.length : 0, + }); + return ciphertext; } - async decryptPayload(ciphertext) { + async decryptPayload(ciphertext, context = {}) { const { decrypt } = await this.ensureCipher(); - return decrypt(ciphertext); + try { + const plaintext = decrypt(ciphertext); + devLogger.debug("[nostr] Decrypted remote signer payload", { + remotePubkey: summarizeHexForLog(this.remotePubkey), + method: context.method || null, + requestId: context.requestId || null, + ciphertextLength: typeof ciphertext === "string" ? ciphertext.length : 0, + plaintextPreview: summarizePayloadPreviewForLog(plaintext), + }); + return plaintext; + } catch (error) { + devLogger.warn("[nostr] Remote signer payload decryption failed", { + remotePubkey: summarizeHexForLog(this.remotePubkey), + method: context.method || null, + requestId: context.requestId || null, + ciphertextLength: typeof ciphertext === "string" ? ciphertext.length : 0, + error: error?.message || String(error), + }); + throw error; + } } async ensureSubscription() { if (this.subscription) { + devLogger.debug("[nostr] Reusing remote signer subscription", { + remotePubkey: summarizeHexForLog(this.remotePubkey), + relayCount: this.relays.length, + }); return this.subscription; } @@ -4403,6 +4570,11 @@ class Nip46RpcClient { // no-op; responses are push-based }); this.subscription = sub; + devLogger.debug("[nostr] Remote signer subscription created", { + remotePubkey: summarizeHexForLog(this.remotePubkey), + relays, + filters, + }); return sub; } @@ -4432,8 +4604,21 @@ class Nip46RpcClient { return; } + const eventId = typeof event.id === "string" ? event.id : ""; + devLogger.debug("[nostr] Remote signer event received", { + eventId, + remotePubkey: summarizeHexForLog(event.pubkey || ""), + clientPubkey: summarizeHexForLog(this.clientPublicKey), + createdAt: Number.isFinite(event.created_at) ? event.created_at : null, + contentLength: typeof event.content === "string" ? event.content.length : 0, + }); + Promise.resolve() - .then(() => this.decryptPayload(event.content)) + .then(() => + this.decryptPayload(event.content, { + requestId: eventId, + }), + ) .then((payload) => { let parsed; try { @@ -4453,6 +4638,14 @@ class Nip46RpcClient { } const pending = this.pendingRequests.get(requestId); + devLogger.debug("[nostr] Remote signer response parsed", { + eventId, + requestId, + remotePubkey: summarizeHexForLog(this.remotePubkey), + method: pending?.method || null, + resultSummary: summarizeRpcResultForLog(pending?.method || "", parsed.result), + errorSummary: summarizePayloadPreviewForLog(parsed.error ?? ""), + }); this.pendingRequests.delete(requestId); clearTimeout(pending.timeoutId); @@ -4485,6 +4678,13 @@ class Nip46RpcClient { } rejectAllPending(error) { + if (this.pendingRequests.size) { + devLogger.warn("[nostr] Rejecting pending remote signer RPC requests", { + count: this.pendingRequests.size, + remotePubkey: summarizeHexForLog(this.remotePubkey), + error: error?.message || String(error), + }); + } for (const [id, pending] of this.pendingRequests.entries()) { clearTimeout(pending.timeoutId); try { @@ -4510,6 +4710,14 @@ class Nip46RpcClient { let lastError = null; + devLogger.debug("[nostr] Remote signer RPC start", { + method, + remotePubkey: summarizeHexForLog(this.remotePubkey), + timeoutMs, + retries, + params: summarizeRpcParamsForLog(method, params), + }); + for (let attempt = 0; attempt <= retries; attempt += 1) { await this.ensureSubscription(); @@ -4520,9 +4728,19 @@ class Nip46RpcClient { params: Array.isArray(params) ? params : [], }; + devLogger.debug("[nostr] Remote signer RPC attempt prepared", { + method, + attempt: attempt + 1, + requestId, + remotePubkey: summarizeHexForLog(this.remotePubkey), + }); + let event; try { - const content = await this.encryptPayload(message); + const content = await this.encryptPayload(message, { + method, + requestId, + }); event = signEventWithPrivateKey( { kind: NIP46_RPC_KIND, @@ -4533,8 +4751,21 @@ class Nip46RpcClient { }, this.clientPrivateKey, ); + devLogger.debug("[nostr] Remote signer RPC event signed", { + method, + attempt: attempt + 1, + requestId, + relayCount: this.relays.length, + contentLength: typeof event.content === "string" ? event.content.length : 0, + }); } catch (error) { lastError = error; + devLogger.warn("[nostr] Remote signer RPC encryption failed", { + method, + attempt: attempt + 1, + requestId, + error: error?.message || String(error), + }); break; } @@ -4545,6 +4776,12 @@ class Nip46RpcClient { `Timed out waiting for remote signer response to ${method}.`, ); timeoutError.code = "nip46-timeout"; + devLogger.warn("[nostr] Remote signer RPC timed out", { + method, + requestId, + attempt: attempt + 1, + timeoutMs, + }); reject(timeoutError); }, timeoutMs); @@ -4554,6 +4791,11 @@ class Nip46RpcClient { timeoutId, method, }); + devLogger.debug("[nostr] Remote signer RPC awaiting response", { + method, + requestId, + attempt: attempt + 1, + }); }); try { @@ -4564,6 +4806,12 @@ class Nip46RpcClient { { timeoutMs: NIP46_PUBLISH_TIMEOUT_MS }, ); assertAnyRelayAccepted(publishResults, { context: method }); + devLogger.debug("[nostr] Remote signer RPC published", { + method, + requestId, + attempt: attempt + 1, + publishResults: summarizeRelayPublishResultsForLog(publishResults), + }); } catch (error) { const pending = this.pendingRequests.get(requestId); if (pending) { @@ -4571,14 +4819,32 @@ class Nip46RpcClient { this.pendingRequests.delete(requestId); } lastError = error; + devLogger.warn("[nostr] Remote signer RPC publish failed", { + method, + requestId, + attempt: attempt + 1, + error: error?.message || String(error), + }); continue; } try { const result = await responsePromise; + devLogger.debug("[nostr] Remote signer RPC response received", { + method, + requestId, + attempt: attempt + 1, + resultSummary: summarizeRpcResultForLog(method, result), + }); return result; } catch (error) { lastError = error; + devLogger.warn("[nostr] Remote signer RPC attempt rejected", { + method, + requestId, + attempt: attempt + 1, + error: error?.message || String(error), + }); if (error?.code === "auth-challenge") { throw error; } @@ -4586,9 +4852,18 @@ class Nip46RpcClient { } if (lastError) { + devLogger.warn("[nostr] Remote signer RPC exhausted", { + method, + remotePubkey: summarizeHexForLog(this.remotePubkey), + error: lastError?.message || String(lastError), + }); throw lastError; } + devLogger.warn("[nostr] Remote signer RPC failed without explicit error", { + method, + remotePubkey: summarizeHexForLog(this.remotePubkey), + }); throw new Error(`Remote signer request for ${method} failed.`); } @@ -4617,6 +4892,11 @@ class Nip46RpcClient { } } + devLogger.debug("[nostr] Remote signer connect RPC acknowledged", { + remotePubkey: summarizeHexForLog(this.remotePubkey), + secretConfirmed: Boolean(this.secret), + resultSummary: summarizeRpcResultForLog("connect", result), + }); return result; } @@ -4632,6 +4912,10 @@ class Nip46RpcClient { throw error; } this.userPubkey = normalizeNostrPubkey(pubkey); + devLogger.debug("[nostr] Remote signer get_public_key resolved", { + remotePubkey: summarizeHexForLog(this.remotePubkey), + userPubkey: summarizeHexForLog(this.userPubkey), + }); return this.userPubkey; } @@ -4641,8 +4925,18 @@ class Nip46RpcClient { timeoutMs: 5000, retries: 0, }); - return typeof result === "string" && result.trim().toLowerCase() === "pong"; + const ok = typeof result === "string" && result.trim().toLowerCase() === "pong"; + devLogger.debug("[nostr] Remote signer ping result", { + remotePubkey: summarizeHexForLog(this.remotePubkey), + ok, + summary: summarizeRpcResultForLog("ping", result), + }); + return ok; } catch (error) { + devLogger.warn("[nostr] Remote signer ping failed", { + remotePubkey: summarizeHexForLog(this.remotePubkey), + error: error?.message || String(error), + }); return false; } } @@ -4683,15 +4977,28 @@ class Nip46RpcClient { } if (typeof result === "object") { + devLogger.debug("[nostr] Remote signer sign_event returned object", { + remotePubkey: summarizeHexForLog(this.remotePubkey), + keys: Object.keys(result).slice(0, 6), + }); return result; } try { - return JSON.parse(result); + const parsed = JSON.parse(result); + devLogger.debug("[nostr] Remote signer sign_event returned JSON", { + remotePubkey: summarizeHexForLog(this.remotePubkey), + keys: parsed && typeof parsed === "object" ? Object.keys(parsed).slice(0, 6) : [], + }); + return parsed; } catch (error) { const failure = new Error("Remote signer returned malformed signed event."); failure.code = "nip46-invalid-response"; failure.cause = error; + devLogger.warn("[nostr] Remote signer sign_event parse failed", { + remotePubkey: summarizeHexForLog(this.remotePubkey), + error: error?.message || String(error), + }); throw failure; } } @@ -4718,6 +5025,12 @@ class Nip46RpcClient { } this.destroyed = true; + devLogger.debug("[nostr] Destroying remote signer client", { + remotePubkey: summarizeHexForLog(this.remotePubkey), + pendingRequests: this.pendingRequests.size, + hasSubscription: Boolean(this.subscription), + }); + if (this.subscription && typeof this.subscription.unsub === "function") { try { this.subscription.unsub(); @@ -5739,11 +6052,17 @@ export class NostrClient { const errorValue = coerceStructuredString(parsed?.error); if (resultValue === "auth_url" && errorValue) { + const handshakeRemotePubkey = payloadResult?.remotePubkey || eventRemotePubkey || ""; + devLogger.debug("[nostr] Handshake provided auth_url challenge", { + eventId: typeof parsed?.id === "string" ? parsed.id : "", + remotePubkey: summarizeHexForLog(handshakeRemotePubkey), + url: summarizeUrlForLog(errorValue), + }); if (typeof onAuthUrl === "function") { try { onAuthUrl(errorValue, { phase: "handshake", - remotePubkey, + remotePubkey: handshakeRemotePubkey, requestId: typeof parsed?.id === "string" ? parsed.id : "", }); } catch (callbackError) { @@ -5863,6 +6182,10 @@ export class NostrClient { return; } try { + devLogger.debug("[nostr] Remote signer auth challenge surfaced", { + url: summarizeUrlForLog(url), + context, + }); const result = onAuthUrl(url, context); if (result && typeof result.then === "function") { await result.catch((error) => { @@ -5955,6 +6278,12 @@ export class NostrClient { timeoutMs: handshakeTimeoutMs, expectedRemotePubkey: parsed.remotePubkey, }); + devLogger.debug("[nostr] Remote signer handshake completed", { + remotePubkey: summarizeHexForLog(handshakeResult?.remotePubkey || parsed.remotePubkey || ""), + algorithm: handshakeResult?.algorithm || null, + relays, + secret: summarizeSecretForLog(secret), + }); } catch (error) { this.emitRemoteSignerChange({ state: "error", @@ -5975,6 +6304,11 @@ export class NostrClient { error.code = "missing-remote-pubkey"; throw error; } + devLogger.debug("[nostr] Remote signer handshake provided final pubkey", { + remotePubkey: summarizeHexForLog(remotePubkey), + algorithm: handshakeAlgorithm || null, + clientPublicKey: summarizeHexForLog(clientPublicKey), + }); } else { const keyPair = await this.createNip46KeyPair( providedClientPrivateKey, @@ -5990,6 +6324,11 @@ export class NostrClient { metadata, userPubkey: parsed.userPubkeyHint || "", }); + devLogger.debug("[nostr] Using bunker URI for remote signer connect", { + remotePubkey: summarizeHexForLog(remotePubkey || parsed.remotePubkey || ""), + relays, + metadataKeys: summarizeMetadataForLog(metadata), + }); } if (!remotePubkey) { @@ -6090,6 +6429,12 @@ export class NostrClient { const signer = this.installNip46Client(client, { userPubkey }); if (remember) { + devLogger.debug("[nostr] Persisting remote signer session", { + remotePubkey: summarizeHexForLog(remotePubkey), + relays, + encryption: client.encryptionAlgorithm || handshakeAlgorithm || "", + permissions: permissions || null, + }); writeStoredNip46Session({ version: 1, clientPrivateKey, @@ -6104,6 +6449,7 @@ export class NostrClient { lastConnectedAt: Date.now(), }); } else { + devLogger.debug("[nostr] Clearing stored remote signer session per request"); clearStoredNip46Session(); } @@ -6173,6 +6519,14 @@ export class NostrClient { const relays = resolveNip46Relays(stored.relays, this.relays); + devLogger.debug("[nostr] Reconnecting to stored remote signer", { + remotePubkey: summarizeHexForLog(stored.remotePubkey || ""), + relays, + encryption: stored.encryption || "", + permissions: stored.permissions || null, + hasSecret: Boolean(stored.secret), + }); + this.emitRemoteSignerChange({ state: "connecting", remotePubkey: stored.remotePubkey, @@ -6206,6 +6560,12 @@ export class NostrClient { lastConnectedAt: Date.now(), }); + devLogger.debug("[nostr] Stored remote signer session refreshed", { + remotePubkey: summarizeHexForLog(stored.remotePubkey || ""), + userPubkey: summarizeHexForLog(userPubkey), + encryption: client.encryptionAlgorithm || stored.encryption || "", + }); + this.emitRemoteSignerChange({ state: "connected", remotePubkey: stored.remotePubkey, @@ -6226,6 +6586,11 @@ export class NostrClient { const shouldForgetStored = forgetOnError || fatalCodes.has(error?.code); if (shouldForgetStored) { clearStoredNip46Session(); + devLogger.warn("[nostr] Stored remote signer session cleared after failure", { + remotePubkey: summarizeHexForLog(stored.remotePubkey || ""), + error: error?.message || String(error), + code: error?.code || null, + }); } const status = {