chore(pairing): durable trace log + keep e2e loopback traffic out of forensics files
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.
This commit is contained in:
parent
e97d8a75f0
commit
21c522ba99
1 changed files with 75 additions and 1 deletions
|
|
@ -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::<Vec<_>>()
|
||||
.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::<RawRequest>(&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<String>) {
|
||||
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
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue