From 21c522ba997149d8b251dbd4a8ec7518584a89d8 Mon Sep 17 00:00:00 2001 From: Avi Date: Fri, 18 Sep 2026 21:00:31 -0500 Subject: [PATCH] chore(pairing): durable trace log + keep e2e loopback traffic out of forensics files MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The Sep 16 forensics file pairing-capture.jsonl turned out to be polluted: the e2e harness pairs over loopback relays but its fake scanner events were appended to the same file (lines 6-7 from today's test runs). Now loopback pairings skip both the capture file and the new pairing-trace.log. pairing-trace.log records the full pairing outcome at every decision point (started, inbound, decrypt-fail, not-a-request, pre-handshake, connect answered, identity adopted, session failed) with timestamps, because backend stderr only reaches the Electron console and /tmp logs get cleaned — a failed live handshake previously left no durable trace. Release binary rebuilt at this commit. --- src/signer/nip46_client.rs | 76 +++++++++++++++++++++++++++++++++++++- 1 file changed, 75 insertions(+), 1 deletion(-) diff --git a/src/signer/nip46_client.rs b/src/signer/nip46_client.rs index db405a3..d7e356a 100644 --- a/src/signer/nip46_client.rs +++ b/src/signer/nip46_client.rs @@ -44,6 +44,26 @@ const PAIRING_TIMEOUT: Duration = Duration::from_secs(300); /// App name advertised to signers during client-initiated pairing. const APP_NAME: &str = "Keynectr"; +/// Append a line to the local pairing trace log so a failed handshake +/// survives the session: backend stderr reaches the dev console only, and +/// nothing else (logs, vault) records why pairing stopped. Local-only debug +/// surface — this file never leaves the machine. +fn pairing_trace(msg: &str) { + let path = std::path::Path::new("/home/avi/Tools/keynctr-debug/pairing-trace.log"); + if let Some(dir) = path.parent() { + let _ = std::fs::create_dir_all(dir); + } + if let Ok(mut f) = std::fs::OpenOptions::new() + .create(true) + .append(true) + .open(path) + { + use std::io::Write; + let now = crate::vault::unix_timestamp().unwrap_or(0); + let _ = writeln!(f, "[{now}] {msg}"); + } +} + /// Internal state for a pending approval. struct PendingApprovalInner { method: String, @@ -468,6 +488,13 @@ impl Nip46ClientSigner { "No usable relays are configured, so there is nowhere to pair over.", )); } + // Loopback-only relay sets belong to the e2e harness: their fake + // scanner events must never pollute the real pairing capture/trace + // files used to dissect live signer handshakes. + let live_capture = relays.iter().any(|r| { + let u = r.to_string().to_lowercase(); + !(u.contains("127.0.0.1") || u.contains("localhost") || u.contains("[::1]")) + }); // Ephemeral session keys: the URI authority is this throwaway key, // never a profile key. The secret proves WE are the app the user @@ -494,6 +521,17 @@ impl Nip46ClientSigner { )); } inner.phase = Nip46Phase::Connecting; + if live_capture { + pairing_trace(&format!( + "pairing started: ephemeral={} relays={}", + keys.public_key().to_hex(), + relays + .iter() + .map(|r| r.to_string()) + .collect::>() + .join(",") + )); + } let signer = self.clone(); let task = tokio::spawn(async move { if let Err(e) = signer @@ -519,6 +557,12 @@ impl Nip46ClientSigner { secret: String, label: String, ) -> Result<(), String> { + // The e2e harness pairs over loopback relays only; its fake-scanner + // events must not pollute the real pairing forensics files. + let live_capture = relays.iter().any(|r| { + let u = r.to_string().to_lowercase(); + !(u.contains("127.0.0.1") || u.contains("localhost") || u.contains("[::1]")) + }); let client = Client::builder() .authenticator(SignerAuthenticator::new(keys.clone())) .build(); @@ -588,7 +632,9 @@ impl Nip46ClientSigner { ); // Local-only debug capture (never leaves this machine): keep the // full event so a failed handshake can be dissected offline. - { + // Loopback (e2e harness) pairings are excluded so test traffic + // never pollutes the forensics files. + if live_capture { let path = std::path::Path::new("/home/avi/Tools/keynctr-debug/pairing-capture.jsonl"); if let Some(dir) = path.parent() { @@ -602,6 +648,11 @@ impl Nip46ClientSigner { use std::io::Write; let _ = writeln!(f, "{}", event.as_json()); } + pairing_trace(&format!( + "inbound 24133 from {} (content len {})", + event.pubkey.to_hex(), + event.content.len() + )); } // Never answer ourselves. if event.pubkey == our_pk { @@ -623,16 +674,30 @@ impl Nip46ClientSigner { "[nip46 pairing] payload did not decrypt: {e} (frame {} chars b64)", event.content.len() ); + if live_capture { + pairing_trace(&format!( + "payload did not decrypt: {e} (frame {} chars b64)", + event.content.len() + )); + } continue; } }; let Ok(request) = serde_json::from_str::(&plain) else { eprintln!("[nip46 pairing] decrypted payload is not a NIP-46 request: {plain}"); + if live_capture { + pairing_trace(&format!( + "decrypted payload is not a NIP-46 request: {plain}" + )); + } continue; }; if request.method != "connect" { // Anything before the handshake is premature — ignore. eprintln!("[nip46 pairing] pre-handshake '{}' ignored", request.method); + if live_capture { + pairing_trace(&format!("pre-handshake '{}' ignored", request.method)); + } continue; } // NIP-46: the client answers the signer's `connect` with the @@ -650,6 +715,9 @@ impl Nip46ClientSigner { return Err(format!("Could not answer the connect request: {e}")); } eprintln!("[nip46 pairing] connect answered; awaiting identity handshake"); + if live_capture { + pairing_trace("connect answered; awaiting identity handshake"); + } // Optional requested_perms ride in params[1]; parse leniently — // a malformed grant list degrades to "no local enforcement", // which defers to the signer's own approval prompts. @@ -868,6 +936,7 @@ impl Nip46ClientSigner { fn fail(&self, message: impl Into) { let message = message.into(); eprintln!("[nip46] session failed: {message}"); + pairing_trace(&format!("session failed: {message}")); if let Ok(mut inner) = self.inner.try_lock() { inner.phase = Nip46Phase::Error(message); inner.task = None; @@ -1606,6 +1675,11 @@ impl Nip46ClientSigner { conn.profile_npub = Some(identity_npub.clone()); } inner.phase = Nip46Phase::Connected; + pairing_trace(&format!( + "identity adopted: npub={} peer={} — CONNECTED", + identity_npub, + peer.to_hex() + )); drop(inner); // Background enrichment (post-Connected by design): look up the