diff --git a/crates/wzp-client/src/dual_path.rs b/crates/wzp-client/src/dual_path.rs new file mode 100644 index 0000000..188e1c0 --- /dev/null +++ b/crates/wzp-client/src/dual_path.rs @@ -0,0 +1,195 @@ +//! Phase 3.5 — dual-path QUIC connect race for P2P hole-punching. +//! +//! When both peers advertised reflex addrs in the +//! DirectCallOffer/Answer flow, the relay cross-wires them into +//! `CallSetup.peer_direct_addr`. This module races a direct QUIC +//! handshake against the existing relay dial and returns whichever +//! completes first — with automatic drop of the loser via +//! `tokio::select!`. +//! +//! Role determination is deterministic and symmetric +//! (`wzp_client::reflect::determine_role`): whichever peer has the +//! lexicographically smaller reflex addr becomes the **Acceptor** +//! (listens on a server-capable endpoint), the other becomes the +//! **Dialer** (dials the peer's addr). Because the rule is +//! identical on both sides, the Acceptor's inbound QUIC session +//! and the Dialer's outbound are the SAME connection — no +//! negotiation needed, no two-conns-per-call confusion. +//! +//! Timeout policy: +//! - Direct path: 2s from the start of `race`. Cone-NAT hole-punch +//! typically completes in < 500ms on a LAN; 2s gives us tolerance +//! for a single QUIC Initial retry on unreliable networks. +//! - Relay path: 10s (existing behavior elsewhere in the codebase). +//! - Overall: `tokio::select!` returns as soon as either succeeds. + +use std::net::SocketAddr; +use std::sync::Arc; +use std::time::Duration; + +use crate::reflect::Role; +use wzp_transport::QuinnTransport; + +/// Which path won the race. Used by the `connect` command for +/// logging + (in the future) metrics. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub enum WinningPath { + Direct, + Relay, +} + +/// Attempt a direct QUIC connection to the peer in parallel with +/// the relay dial and return the winning `QuinnTransport`. +/// +/// `role` selects the direction of the direct attempt: +/// - `Role::Acceptor` creates a server-capable endpoint and waits +/// for the peer to dial in. +/// - `Role::Dialer` creates a client-only endpoint and dials +/// `peer_direct_addr`. +/// +/// The relay path is always attempted in parallel as a fallback so +/// the race ALWAYS produces a working transport unless both paths +/// genuinely fail (network partition). Returns +/// `Err(anyhow::anyhow!(...))` if both paths fail within the +/// timeout. +#[allow(clippy::too_many_arguments)] +pub async fn race( + role: Role, + peer_direct_addr: SocketAddr, + relay_addr: SocketAddr, + room_sni: String, + call_sni: String, +) -> anyhow::Result<(Arc, WinningPath)> { + // Rustls provider must be installed before any quinn endpoint + // is created. Install attempt is idempotent. + let _ = rustls::crypto::ring::default_provider().install_default(); + + // Build the direct-path endpoint + future based on role. + // Each future returns an already-wrapped `QuinnTransport` so we + // don't need a direct `quinn::Connection` type in scope here + // (this crate doesn't depend on quinn directly). + let direct_ep: wzp_transport::Endpoint; + let direct_fut: std::pin::Pin< + Box> + Send>, + >; + + match role { + Role::Acceptor => { + let (sc, _cert_der) = wzp_transport::server_config(); + let bind: SocketAddr = "0.0.0.0:0".parse().unwrap(); + let ep = wzp_transport::create_endpoint(bind, Some(sc))?; + tracing::info!( + local_addr = ?ep.local_addr().ok(), + "dual_path: A-role endpoint up, awaiting peer dial" + ); + let ep_for_fut = ep.clone(); + direct_fut = Box::pin(async move { + // `wzp_transport::accept` wraps the same + // `endpoint.accept().await?.await?` dance we want + // and maps errors into TransportError for us. + let conn = wzp_transport::accept(&ep_for_fut) + .await + .map_err(|e| anyhow::anyhow!("direct accept: {e}"))?; + Ok(QuinnTransport::new(conn)) + }); + direct_ep = ep; + } + Role::Dialer => { + let bind: SocketAddr = "0.0.0.0:0".parse().unwrap(); + let ep = wzp_transport::create_endpoint(bind, None)?; + tracing::info!( + local_addr = ?ep.local_addr().ok(), + %peer_direct_addr, + "dual_path: D-role endpoint up, dialing peer" + ); + let ep_for_fut = ep.clone(); + let client_cfg = wzp_transport::client_config(); + let sni = call_sni.clone(); + direct_fut = Box::pin(async move { + let conn = + wzp_transport::connect(&ep_for_fut, peer_direct_addr, &sni, client_cfg) + .await + .map_err(|e| anyhow::anyhow!("direct dial: {e}"))?; + Ok(QuinnTransport::new(conn)) + }); + direct_ep = ep; + } + } + + // Relay path: classic dial to the relay's media room. + let relay_bind: SocketAddr = "0.0.0.0:0".parse().unwrap(); + let relay_ep = wzp_transport::create_endpoint(relay_bind, None)?; + let relay_ep_for_fut = relay_ep.clone(); + let relay_client_cfg = wzp_transport::client_config(); + let relay_sni = room_sni.clone(); + let relay_fut = async move { + let conn = + wzp_transport::connect(&relay_ep_for_fut, relay_addr, &relay_sni, relay_client_cfg) + .await + .map_err(|e| anyhow::anyhow!("relay dial: {e}"))?; + Ok::<_, anyhow::Error>(QuinnTransport::new(conn)) + }; + + // Race the two with a shared 2s ceiling on the direct attempt. + // Pin both so we can poll them from multiple branches of the + // select without moving the futures — the "direct failed, wait + // for relay" and "relay failed, wait for direct" fallback paths + // below need to await the OPPOSITE future after the winning + // branch fires. Without pinning, tokio::select! moves the + // future out and we can't touch it again. + tracing::info!(?role, %peer_direct_addr, %relay_addr, "dual_path: racing direct vs relay"); + let direct_timed = tokio::time::timeout(Duration::from_secs(2), direct_fut); + tokio::pin!(direct_timed, relay_fut); + + let result = tokio::select! { + biased; // prefer direct win if both arrive in the same tick + direct_result = &mut direct_timed => { + match direct_result { + Ok(Ok(transport)) => { + tracing::info!(%peer_direct_addr, "dual_path: direct WON"); + Ok((Arc::new(transport), WinningPath::Direct)) + } + Ok(Err(e)) => { + // Direct failed — fall back to waiting for relay. + tracing::warn!(error = %e, "dual_path: direct failed, awaiting relay"); + match tokio::time::timeout(Duration::from_secs(5), &mut relay_fut).await { + Ok(Ok(transport)) => Ok((Arc::new(transport), WinningPath::Relay)), + Ok(Err(e2)) => Err(anyhow::anyhow!("both paths failed: direct={e}, relay={e2}")), + Err(_) => Err(anyhow::anyhow!("both paths failed: direct={e}, relay=timeout(5s)")), + } + } + Err(_elapsed) => { + tracing::warn!("dual_path: direct timed out (2s), awaiting relay"); + match tokio::time::timeout(Duration::from_secs(5), &mut relay_fut).await { + Ok(Ok(transport)) => Ok((Arc::new(transport), WinningPath::Relay)), + Ok(Err(e2)) => Err(anyhow::anyhow!("direct timeout + relay failed: {e2}")), + Err(_) => Err(anyhow::anyhow!("direct timeout + relay timeout")), + } + } + } + } + relay_result = &mut relay_fut => { + match relay_result { + Ok(transport) => { + tracing::info!("dual_path: relay WON (direct still pending)"); + Ok((Arc::new(transport), WinningPath::Relay)) + } + Err(e) => { + tracing::warn!(error = %e, "dual_path: relay failed, awaiting direct remainder"); + match tokio::time::timeout(Duration::from_millis(1500), &mut direct_timed).await { + Ok(Ok(Ok(transport))) => Ok((Arc::new(transport), WinningPath::Direct)), + _ => Err(anyhow::anyhow!("relay failed + direct unavailable: {e}")), + } + } + } + } + }; + + // Drop both endpoints once the winner is stored in result. The + // winning transport owns its own connection so dropping the + // endpoint won't kill it. + drop(direct_ep); + drop(relay_ep); + + result +} diff --git a/crates/wzp-client/src/lib.rs b/crates/wzp-client/src/lib.rs index bcc029c..679dce7 100644 --- a/crates/wzp-client/src/lib.rs +++ b/crates/wzp-client/src/lib.rs @@ -32,6 +32,7 @@ pub mod drift_test; pub mod echo_test; pub mod featherchat; pub mod handshake; +pub mod dual_path; pub mod metrics; pub mod reflect; pub mod sweep; diff --git a/crates/wzp-client/src/reflect.rs b/crates/wzp-client/src/reflect.rs index eebb015..16096c5 100644 --- a/crates/wzp-client/src/reflect.rs +++ b/crates/wzp-client/src/reflect.rs @@ -223,6 +223,58 @@ pub async fn detect_nat_type( } } +/// Role assignment for the Phase 3.5 dual-path QUIC race. +/// +/// Both peers already know two strings at CallSetup time: their +/// own server-reflexive address (queried via Phase 1 Reflect) and +/// the peer's (carried in `CallSetup.peer_direct_addr`). To avoid +/// a negotiation round-trip, both sides compare the two strings +/// lexicographically and agree on a deterministic role: +/// +/// - **Acceptor** — lexicographically smaller addr. Listens for +/// an incoming direct connection from the peer. Does NOT dial. +/// - **Dialer** — lexicographically larger addr. Dials the +/// peer's direct addr. Does NOT listen. +/// +/// Both roles ALSO dial the relay in parallel as a fallback. +/// Whichever future (direct or relay) completes first is used as +/// the media transport. Because the role is deterministic and +/// symmetric, both peers end up holding the same underlying QUIC +/// session on the direct path — A's accepted conn and D's dialed +/// conn are literally the same connection. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub enum Role { + /// This peer listens for the direct incoming connection. + Acceptor, + /// This peer dials the peer's direct address. + Dialer, +} + +/// Compute the deterministic role for this peer in the dual-path +/// race. Returns `None` when no direct attempt is possible — +/// either peer didn't advertise a reflex addr, or the two addrs +/// are identical (same host on loopback / mis-advertised). +/// +/// The caller should treat `None` as "skip direct, relay-only". +pub fn determine_role( + own_reflex_addr: Option<&str>, + peer_reflex_addr: Option<&str>, +) -> Option { + let (own, peer) = match (own_reflex_addr, peer_reflex_addr) { + (Some(o), Some(p)) => (o, p), + _ => return None, + }; + match own.cmp(peer) { + std::cmp::Ordering::Less => Some(Role::Acceptor), + std::cmp::Ordering::Greater => Some(Role::Dialer), + // Equal addrs should never happen in production (both + // peers behind the same NAT mapping + same port would be + // a degenerate case). Guard against it so we don't infinite- + // loop waiting for a connection to ourselves. + std::cmp::Ordering::Equal => None, + } +} + /// Pure-function NAT classifier — split out for unit testing /// without touching the network. pub fn classify_nat(probes: &[NatProbeResult]) -> (NatType, Option) { @@ -326,6 +378,65 @@ mod tests { assert_eq!(addr.as_deref(), Some("192.0.2.1:4433")); } + #[test] + fn determine_role_smaller_is_acceptor() { + // Lexicographic: "192.0.2.1:4433" < "198.51.100.9:4433" + assert_eq!( + determine_role(Some("192.0.2.1:4433"), Some("198.51.100.9:4433")), + Some(Role::Acceptor) + ); + } + + #[test] + fn determine_role_larger_is_dialer() { + assert_eq!( + determine_role(Some("198.51.100.9:4433"), Some("192.0.2.1:4433")), + Some(Role::Dialer) + ); + } + + #[test] + fn determine_role_port_difference_matters() { + // Same ip, different ports — string compare still works + // because "4433" < "54321". + assert_eq!( + determine_role(Some("127.0.0.1:4433"), Some("127.0.0.1:54321")), + Some(Role::Acceptor) + ); + assert_eq!( + determine_role(Some("127.0.0.1:54321"), Some("127.0.0.1:4433")), + Some(Role::Dialer) + ); + } + + #[test] + fn determine_role_equal_addrs_is_none() { + assert_eq!( + determine_role(Some("192.0.2.1:4433"), Some("192.0.2.1:4433")), + None + ); + } + + #[test] + fn determine_role_missing_side_is_none() { + assert_eq!(determine_role(None, Some("192.0.2.1:4433")), None); + assert_eq!(determine_role(Some("192.0.2.1:4433"), None), None); + assert_eq!(determine_role(None, None), None); + } + + #[test] + fn determine_role_is_symmetric_across_peers() { + // Both peers compute roles independently; they must end + // up with opposite assignments (one Acceptor, one Dialer) + // so that each side ends up talking to the other. + let a = "192.0.2.1:4433"; + let b = "198.51.100.9:4433"; + let alice_role = determine_role(Some(a), Some(b)); + let bob_role = determine_role(Some(b), Some(a)); + assert_eq!(alice_role, Some(Role::Acceptor)); + assert_eq!(bob_role, Some(Role::Dialer)); + } + #[test] fn classify_one_success_one_failure_is_unknown() { let probes = vec![mk(Some("192.0.2.1:4433")), mk(None)]; diff --git a/crates/wzp-client/tests/dual_path.rs b/crates/wzp-client/tests/dual_path.rs new file mode 100644 index 0000000..55521af --- /dev/null +++ b/crates/wzp-client/tests/dual_path.rs @@ -0,0 +1,199 @@ +//! Phase 3.5 integration tests for the dual-path QUIC race. +//! +//! The race takes a role (Acceptor or Dialer), a peer_direct_addr, +//! a relay_addr, and two SNI strings, then returns whichever QUIC +//! handshake completes first wrapped in a `QuinnTransport`. These +//! tests validate that: +//! +//! 1. On loopback with two real clients playing A + D roles, the +//! direct path wins (fewer hops than relay). +//! 2. When the direct peer is dead (nothing listening) but the +//! relay is up, the relay wins within the fallback window. +//! 3. When both paths are dead, the race errors cleanly rather +//! than hanging forever. +//! +//! The "relay" in these tests is a minimal mock that just accepts +//! an incoming QUIC connection and drops it — we don't need any +//! protocol handling, just a TCP-ish listen-and-accept. + +use std::net::{Ipv4Addr, SocketAddr}; +use std::time::Duration; + +use wzp_client::dual_path::{race, WinningPath}; +use wzp_client::reflect::Role; +use wzp_transport::{create_endpoint, server_config}; + +/// Spin up a "relay-ish" mock server on loopback that accepts +/// incoming QUIC connections and does nothing with them. Used to +/// give the relay branch of the race a real target to dial. +/// Returns the bound address + a join handle (kept alive to keep +/// the endpoint up). +async fn spawn_mock_relay() -> (SocketAddr, tokio::task::JoinHandle<()>) { + let _ = rustls::crypto::ring::default_provider().install_default(); + let (sc, _cert_der) = server_config(); + let bind: SocketAddr = (Ipv4Addr::LOCALHOST, 0).into(); + let ep = create_endpoint(bind, Some(sc)).expect("relay endpoint"); + let addr = ep.local_addr().expect("local_addr"); + + let handle = tokio::spawn(async move { + // Accept loop — hold the connection alive for a short + // while so the race result isn't killed by the peer + // closing before the winning transport is returned. + while let Some(incoming) = ep.accept().await { + if let Ok(_conn) = incoming.await { + tokio::time::sleep(Duration::from_secs(5)).await; + } + } + }); + (addr, handle) +} + +// ----------------------------------------------------------------------- +// Test 1: direct path wins when both sides are up +// ----------------------------------------------------------------------- +// +// Spawn a mock relay, then set up a two-client test where one +// client plays the Acceptor role and the other plays the Dialer +// role. The Dialer's `peer_direct_addr` is the Acceptor's listen +// address. Because the direct path is a single loopback hop and +// the relay dial also terminates on loopback, both complete +// essentially instantly — the `biased` tokio::select in race() +// should pick direct. + +#[tokio::test(flavor = "multi_thread", worker_threads = 4)] +async fn dual_path_direct_wins_on_loopback() { + let _ = rustls::crypto::ring::default_provider().install_default(); + let (relay_addr, _relay_handle) = spawn_mock_relay().await; + + // Acceptor task: run race(Role::Acceptor, peer_addr_placeholder, ...). + // Since the acceptor doesn't dial, the peer_direct_addr arg is + // unused on the direct branch but we still pass a placeholder + // because the API takes one. Use a stub addr that would error + // if it were ever dialed — proving the Acceptor really doesn't + // reach it. + let unused_addr: SocketAddr = "127.0.0.1:2".parse().unwrap(); + + // We can't race both sides in the same task because each race + // call has its own direct endpoint that needs to talk to the + // OTHER side's endpoint. So spawn the Acceptor in a task and + // let it expose its listen addr via a oneshot back to the test, + // then run the Dialer in the test's main task. + // + // There's a chicken-and-egg issue: the Acceptor's listen addr + // is only known after race() creates its endpoint. To avoid + // reaching into race()'s internals, we instead play a slight + // trick: create the Acceptor's endpoint ourselves (outside + // race()) to learn its addr, spin up an accept loop on it + // ourselves, and pass THAT addr as the Dialer's peer addr. + // This tests the Dialer->Acceptor handshake end-to-end without + // running the full race() on both sides. + + let (sc, _cert_der) = server_config(); + let acceptor_bind: SocketAddr = (Ipv4Addr::LOCALHOST, 0).into(); + let acceptor_ep = create_endpoint(acceptor_bind, Some(sc)).expect("acceptor ep"); + let acceptor_listen_addr = acceptor_ep.local_addr().expect("acceptor addr"); + + // Drop the external acceptor after the test finishes, not + // before — spawn a dedicated accept task. + let acceptor_accept_task = tokio::spawn(async move { + // Accept one connection and hold it for a while so the + // Dialer side can complete its QUIC handshake. + if let Some(incoming) = acceptor_ep.accept().await { + if let Ok(_conn) = incoming.await { + tokio::time::sleep(Duration::from_secs(5)).await; + } + } + }); + + // Now run the Dialer in the race — peer_direct_addr = acceptor's + // listen addr. The relay is the mock from above. Direct path + // should win. + let result = race( + Role::Dialer, + acceptor_listen_addr, + relay_addr, + "test-room".into(), + "call-test".into(), + ) + .await + .expect("race must succeed"); + + assert_eq!(result.1, WinningPath::Direct, "direct should win on loopback"); + + // Cancel the acceptor accept task so the test finishes. + acceptor_accept_task.abort(); + // Suppress unused-var warning for the placeholder. + let _ = unused_addr; +} + +// ----------------------------------------------------------------------- +// Test 2: relay wins when the direct peer is dead +// ----------------------------------------------------------------------- +// +// Dialer role, peer_direct_addr = a port nothing is listening on, +// relay is the working mock. Direct dial will sit waiting for a +// QUIC handshake that never comes; the 2s direct timeout kicks in +// and the relay path wins the fallback. + +#[tokio::test(flavor = "multi_thread", worker_threads = 4)] +async fn dual_path_relay_wins_when_direct_is_dead() { + let _ = rustls::crypto::ring::default_provider().install_default(); + let (relay_addr, _relay_handle) = spawn_mock_relay().await; + + // A port that nothing is listening on — dead direct target. + // Port 1 on loopback is almost never bound and UDP packets to + // it will be dropped silently, so the QUIC handshake times out. + let dead_peer: SocketAddr = "127.0.0.1:1".parse().unwrap(); + + let result = race( + Role::Dialer, + dead_peer, + relay_addr, + "test-room".into(), + "call-test".into(), + ) + .await + .expect("race must succeed via relay fallback"); + + assert_eq!( + result.1, + WinningPath::Relay, + "relay should win when direct dial has nowhere to land" + ); +} + +// ----------------------------------------------------------------------- +// Test 3: race errors cleanly when both paths are dead +// ----------------------------------------------------------------------- +// +// Dialer role, peer_direct_addr = dead, relay_addr = dead. +// Expected: race returns an Err within ~7s (2s direct timeout + +// 5s relay timeout fallback). + +#[tokio::test(flavor = "multi_thread", worker_threads = 4)] +async fn dual_path_errors_cleanly_when_both_paths_dead() { + let _ = rustls::crypto::ring::default_provider().install_default(); + + let dead_peer: SocketAddr = "127.0.0.1:1".parse().unwrap(); + let dead_relay: SocketAddr = "127.0.0.1:2".parse().unwrap(); + + let start = std::time::Instant::now(); + let result = race( + Role::Dialer, + dead_peer, + dead_relay, + "test-room".into(), + "call-test".into(), + ) + .await; + let elapsed = start.elapsed(); + + assert!(result.is_err(), "both-dead must return Err"); + // Upper bound: direct 2s timeout + relay 5s fallback + small + // slack for scheduling. If this blows, something is looping. + assert!( + elapsed < Duration::from_secs(10), + "race took too long to give up: {:?}", + elapsed + ); +} diff --git a/desktop/index.html b/desktop/index.html index 4ae4bdd..303160c 100644 --- a/desktop/index.html +++ b/desktop/index.html @@ -173,6 +173,20 @@ DRED debug logs (verbose, dev only) + + +

Identity

diff --git a/desktop/src-tauri/src/engine.rs b/desktop/src-tauri/src/engine.rs index c72e6bd..4e5fb05 100644 --- a/desktop/src-tauri/src/engine.rs +++ b/desktop/src-tauri/src/engine.rs @@ -297,6 +297,11 @@ impl CallEngine { _os_aec: bool, quality: String, reuse_endpoint: Option, + // Phase 3.5: caller did the dual-path race and picked a + // winning transport (direct or relay). If Some, we skip + // our own wzp_transport::connect step and use this + // directly. If None, existing Phase 0 behavior. + pre_connected_transport: Option>, event_cb: F, ) -> Result where @@ -309,7 +314,13 @@ impl CallEngine { // decode, first playout-ring write, and the C++ Oboe first-callback // logs (which already exist in cpp/oboe_bridge.cpp). let call_t0 = std::time::Instant::now(); - info!(%relay, %room, %alias, %quality, has_reuse = reuse_endpoint.is_some(), t_ms = 0u128, "CallEngine::start (android) invoked"); + info!( + %relay, %room, %alias, %quality, + has_reuse = reuse_endpoint.is_some(), + has_pre_connected = pre_connected_transport.is_some(), + t_ms = 0u128, + "CallEngine::start (android) invoked" + ); let _ = rustls::crypto::ring::default_provider().install_default(); let relay_addr: SocketAddr = relay.parse()?; @@ -322,41 +333,48 @@ impl CallEngine { let fingerprint = fp.to_string(); info!(%fp, "identity loaded"); - // QUIC transport + handshake. - // - // If a `reuse_endpoint` was passed in (the direct-call path, where we - // already opened a quinn::Endpoint for the signal connection), reuse - // it: a second quinn::Endpoint on Android silently fails to complete - // the QUIC handshake against the same relay. Reusing the existing - // socket lets quinn multiplex the signal + media connections on one - // UDP port. - let endpoint = if let Some(ep) = reuse_endpoint { - info!(local_addr = ?ep.local_addr().ok(), "reusing signal endpoint for media connection"); - ep + // Transport source: either the pre-connected one from the + // dual-path race (Phase 3.5) or build a fresh one here. + let transport = if let Some(t) = pre_connected_transport { + info!(t_ms = call_t0.elapsed().as_millis(), "first-join diag: using pre-connected transport from dual-path race"); + t } else { - let bind_addr: SocketAddr = "0.0.0.0:0".parse().unwrap(); - let ep = wzp_transport::create_endpoint(bind_addr, None) - .map_err(|e| { error!("create_endpoint failed: {e}"); e })?; - info!(local_addr = ?ep.local_addr().ok(), "created new endpoint, dialing relay"); - ep + // QUIC transport + handshake (Phase 0 relay-only path). + // + // If a `reuse_endpoint` was passed in (the direct-call path, where we + // already opened a quinn::Endpoint for the signal connection), reuse + // it: a second quinn::Endpoint on Android silently fails to complete + // the QUIC handshake against the same relay. Reusing the existing + // socket lets quinn multiplex the signal + media connections on one + // UDP port. + let endpoint = if let Some(ep) = reuse_endpoint { + info!(local_addr = ?ep.local_addr().ok(), "reusing signal endpoint for media connection"); + ep + } else { + let bind_addr: SocketAddr = "0.0.0.0:0".parse().unwrap(); + let ep = wzp_transport::create_endpoint(bind_addr, None) + .map_err(|e| { error!("create_endpoint failed: {e}"); e })?; + info!(local_addr = ?ep.local_addr().ok(), "created new endpoint, dialing relay"); + ep + }; + let client_config = wzp_transport::client_config(); + let conn = match tokio::time::timeout( + std::time::Duration::from_secs(10), + wzp_transport::connect(&endpoint, relay_addr, &room, client_config), + ).await { + Ok(Ok(c)) => c, + Ok(Err(e)) => { + error!("connect failed: {e}"); + return Err(e.into()); + } + Err(_) => { + error!("connect TIMED OUT after 10s — QUIC handshake never completed. Relay may be unreachable from this endpoint."); + return Err(anyhow::anyhow!("QUIC connect timeout (10s)")); + } + }; + info!(t_ms = call_t0.elapsed().as_millis(), "first-join diag: QUIC connection established, performing handshake"); + Arc::new(wzp_transport::QuinnTransport::new(conn)) }; - let client_config = wzp_transport::client_config(); - let conn = match tokio::time::timeout( - std::time::Duration::from_secs(10), - wzp_transport::connect(&endpoint, relay_addr, &room, client_config), - ).await { - Ok(Ok(c)) => c, - Ok(Err(e)) => { - error!("connect failed: {e}"); - return Err(e.into()); - } - Err(_) => { - error!("connect TIMED OUT after 10s — QUIC handshake never completed. Relay may be unreachable from this endpoint."); - return Err(anyhow::anyhow!("QUIC connect timeout (10s)")); - } - }; - info!(t_ms = call_t0.elapsed().as_millis(), "first-join diag: QUIC connection established, performing handshake"); - let transport = Arc::new(wzp_transport::QuinnTransport::new(conn)); let _session = wzp_client::handshake::perform_handshake( &*transport, @@ -872,12 +890,20 @@ impl CallEngine { _os_aec: bool, quality: String, reuse_endpoint: Option, + // Phase 3.5: caller did the dual-path race and picked a + // winning transport. If Some, skip our own connect step. + pre_connected_transport: Option>, event_cb: F, ) -> Result where F: Fn(&str, &str) + Send + Sync + 'static, { - info!(%relay, %room, %alias, %quality, has_reuse = reuse_endpoint.is_some(), "CallEngine::start (desktop) invoked"); + info!( + %relay, %room, %alias, %quality, + has_reuse = reuse_endpoint.is_some(), + has_pre_connected = pre_connected_transport.is_some(), + "CallEngine::start (desktop) invoked" + ); let _ = rustls::crypto::ring::default_provider().install_default(); let relay_addr: SocketAddr = relay.parse()?; @@ -899,24 +925,31 @@ impl CallEngine { let fingerprint = fp.to_string(); info!(%fp, "identity loaded"); - // Connect — reuse the signal endpoint if the direct-call path gave - // us one, otherwise create a fresh one (SFU room join path). - let endpoint = if let Some(ep) = reuse_endpoint { - info!(local_addr = ?ep.local_addr().ok(), "reusing signal endpoint for media connection"); - ep + // Transport source: either the pre-connected dual-path + // winner (Phase 3.5) or build a fresh relay connection here. + let transport = if let Some(t) = pre_connected_transport { + info!("using pre-connected transport from dual-path race"); + t } else { - let bind_addr: SocketAddr = "0.0.0.0:0".parse().unwrap(); - let ep = wzp_transport::create_endpoint(bind_addr, None) - .map_err(|e| { error!("create_endpoint failed: {e}"); e })?; - info!(local_addr = ?ep.local_addr().ok(), "created new endpoint, dialing relay"); - ep + // Connect — reuse the signal endpoint if the direct-call path gave + // us one, otherwise create a fresh one (SFU room join path). + let endpoint = if let Some(ep) = reuse_endpoint { + info!(local_addr = ?ep.local_addr().ok(), "reusing signal endpoint for media connection"); + ep + } else { + let bind_addr: SocketAddr = "0.0.0.0:0".parse().unwrap(); + let ep = wzp_transport::create_endpoint(bind_addr, None) + .map_err(|e| { error!("create_endpoint failed: {e}"); e })?; + info!(local_addr = ?ep.local_addr().ok(), "created new endpoint, dialing relay"); + ep + }; + let client_config = wzp_transport::client_config(); + let conn = wzp_transport::connect(&endpoint, relay_addr, &room, client_config) + .await + .map_err(|e| { error!("connect failed: {e}"); e })?; + info!("QUIC connection established, performing handshake"); + Arc::new(wzp_transport::QuinnTransport::new(conn)) }; - let client_config = wzp_transport::client_config(); - let conn = wzp_transport::connect(&endpoint, relay_addr, &room, client_config) - .await - .map_err(|e| { error!("connect failed: {e}"); e })?; - info!("QUIC connection established, performing handshake"); - let transport = Arc::new(wzp_transport::QuinnTransport::new(conn)); // Handshake let _session = wzp_client::handshake::perform_handshake( diff --git a/desktop/src-tauri/src/lib.rs b/desktop/src-tauri/src/lib.rs index b8cff26..2e73131 100644 --- a/desktop/src-tauri/src/lib.rs +++ b/desktop/src-tauri/src/lib.rs @@ -31,11 +31,58 @@ use engine::CallEngine; use serde::Serialize; use std::path::PathBuf; +use std::sync::atomic::{AtomicBool, Ordering}; use std::sync::{Arc, OnceLock}; use tauri::{Emitter, Manager}; use tokio::sync::Mutex; use wzp_proto::MediaTransport; +// ─── Call-flow debug logs (GUI-gated) ──────────────────────────────── +// +// Runtime-toggleable verbose logging for every step in the +// signaling + call setup path. When the user enables "Call flow +// debug logs" in the settings panel, `emit_call_debug!` fires a +// `call-debug-log` Tauri event that JS picks up and renders into a +// rolling debug panel so the user can see exactly where a call +// progressed or stalled — no logcat parsing needed. +// +// Mirrors the existing `wzp_codec::dred_verbose_logs` pattern. + +static CALL_DEBUG_LOGS: AtomicBool = AtomicBool::new(false); + +#[inline] +fn call_debug_logs_enabled() -> bool { + CALL_DEBUG_LOGS.load(Ordering::Relaxed) +} + +fn set_call_debug_logs_internal(on: bool) { + CALL_DEBUG_LOGS.store(on, Ordering::Relaxed); +} + +/// Emit a `call-debug-log` event to the JS side IF the flag is on. +/// Also mirrors to `tracing::info!` so logcat keeps its copy +/// regardless of the flag — the toggle only controls the GUI +/// overlay, not the underlying Android log stream. +fn emit_call_debug( + app: &tauri::AppHandle, + step: &str, + details: serde_json::Value, +) { + tracing::info!(step, ?details, "call-debug"); + if !call_debug_logs_enabled() { + return; + } + let payload = serde_json::json!({ + "ts_ms": std::time::SystemTime::now() + .duration_since(std::time::UNIX_EPOCH) + .map(|d| d.as_millis() as u64) + .unwrap_or(0), + "step": step, + "details": details, + }); + let _ = app.emit("call-debug-log", payload); +} + /// Short git hash captured at compile time by build.rs. const GIT_HASH: &str = env!("WZP_GIT_HASH"); @@ -126,6 +173,22 @@ fn get_dred_verbose_logs() -> bool { wzp_codec::dred_verbose_logs() } +/// Phase 3.5 call-flow debug logs toggle. Gates the live +/// `call-debug-log` Tauri events that the GUI renders into a +/// rolling debug panel. Does NOT affect logcat — tracing::info +/// always runs regardless so the Android log stream keeps its +/// copy. +#[tauri::command] +fn set_call_debug_logs(enabled: bool) { + set_call_debug_logs_internal(enabled); + tracing::info!(enabled, "call-flow debug logs toggled"); +} + +#[tauri::command] +fn get_call_debug_logs() -> bool { + call_debug_logs_enabled() +} + /// Ping a relay to check if it's online, measure RTT, and get server identity. #[tauri::command] async fn ping_relay(relay: String) -> Result { @@ -271,28 +334,114 @@ async fn connect( #[allow(non_snake_case)] peer_direct_addr: Option, ) -> Result { + emit_call_debug(&app, "connect:start", serde_json::json!({ + "relay": relay, + "room": room, + "peer_direct_addr": peer_direct_addr, + })); let mut engine_lock = state.engine.lock().await; if engine_lock.is_some() { + emit_call_debug(&app, "connect:already_connected", serde_json::json!({})); return Err("already connected".into()); } - if let Some(ref addr) = peer_direct_addr { - tracing::info!(%addr, %relay, %room, "connect: peer_direct_addr supplied — hole-punching candidate logged (Phase 3.5 will race direct vs relay here)"); - } else { - tracing::info!(%relay, %room, "connect: no peer_direct_addr — relay-only path"); - } + // Phase 3.5: dual-path QUIC race. + // + // If the relay cross-wired a peer_direct_addr into the + // CallSetup, we read our own reflex addr from SignalState + // (populated earlier by place_call/answer_call's reflect query) + // and use determine_role() to decide whether we're the + // Acceptor (smaller addr, listens) or Dialer (larger addr, + // dials). Both roles also dial the relay in parallel as a + // fallback. Whichever transport completes first becomes the + // media transport we hand to CallEngine::start. + // + // If ANY of the inputs is missing (no peer_direct_addr, no + // own_reflex_addr, unparseable addrs, equal addrs), we skip + // the race entirely and fall back to the pure-relay path — + // identical to Phase 0 behavior. + let own_reflex_addr = state.signal.lock().await.own_reflex_addr.clone(); + let peer_addr_parsed: Option = peer_direct_addr + .as_deref() + .and_then(|s| s.parse().ok()); + let relay_addr_parsed: Option = relay.parse().ok(); + let role = wzp_client::reflect::determine_role( + own_reflex_addr.as_deref(), + peer_direct_addr.as_deref(), + ); + + let pre_connected_transport: Option> = + match (role, peer_addr_parsed, relay_addr_parsed) { + (Some(r), Some(peer_addr), Some(relay_sockaddr)) => { + tracing::info!( + role = ?r, + %peer_addr, + %relay, + %room, + own = ?own_reflex_addr, + "connect: starting dual-path race" + ); + emit_call_debug(&app, "connect:dual_path_race_start", serde_json::json!({ + "role": format!("{:?}", r), + "peer_addr": peer_addr.to_string(), + "relay_addr": relay_sockaddr.to_string(), + "own_reflex_addr": own_reflex_addr, + })); + let room_sni = room.clone(); + let call_sni = format!("call-{room}"); + match wzp_client::dual_path::race(r, peer_addr, relay_sockaddr, room_sni, call_sni).await { + Ok((transport, path)) => { + tracing::info!(?path, "connect: dual-path race resolved"); + emit_call_debug(&app, "connect:dual_path_race_won", serde_json::json!({ + "path": format!("{:?}", path), + })); + Some(transport) + } + Err(e) => { + // Both paths failed — surface to the user. + // CallEngine::start below with None will try + // the relay once more using the old code path + // (which reuses the signal endpoint and has a + // longer timeout) so we don't unconditionally + // fail the call on a transient race blip. + tracing::warn!(error = %e, "connect: dual-path race failed, falling back to classic relay connect"); + emit_call_debug(&app, "connect:dual_path_race_failed", serde_json::json!({ + "error": e.to_string(), + })); + None + } + } + } + _ => { + tracing::info!( + has_peer = peer_direct_addr.is_some(), + has_own = own_reflex_addr.is_some(), + ?role, + %relay, + %room, + "connect: skipping dual-path race (missing inputs), relay-only" + ); + emit_call_debug(&app, "connect:dual_path_skipped", serde_json::json!({ + "has_peer": peer_direct_addr.is_some(), + "has_own": own_reflex_addr.is_some(), + "role": format!("{:?}", role), + })); + None + } + }; // If we previously opened a quinn::Endpoint for the signaling connection // (direct-call path), reuse it so the media connection shares the same // UDP socket. This side-steps the Android issue where a second // quinn::Endpoint silently hangs in the QUIC handshake. let reuse_endpoint = state.signal.lock().await.endpoint.clone(); - if reuse_endpoint.is_some() { + if reuse_endpoint.is_some() && pre_connected_transport.is_none() { tracing::info!("connect: reusing existing signal endpoint for media connection"); } let app_clone = app.clone(); - match CallEngine::start(relay, room, alias, os_aec, quality, reuse_endpoint, move |event_kind, message| { + emit_call_debug(&app, "connect:call_engine_starting", serde_json::json!({})); + match CallEngine::start(relay, room, alias, os_aec, quality, reuse_endpoint, pre_connected_transport, move |event_kind, message| { let _ = app_clone.emit( "call-event", CallEvent { @@ -305,9 +454,13 @@ async fn connect( { Ok(eng) => { *engine_lock = Some(eng); + emit_call_debug(&app, "connect:call_engine_started", serde_json::json!({})); Ok("connected".into()) } - Err(e) => Err(format!("{e}")), + Err(e) => { + emit_call_debug(&app, "connect:call_engine_failed", serde_json::json!({ "error": e.to_string() })); + Err(format!("{e}")) + } } } @@ -489,6 +642,12 @@ struct SignalState { /// replace the sender — the old receiver sees a `Cancelled` error /// and the caller retries. pending_reflect: Option>, + /// Phase 3.5: this client's own server-reflexive address as last + /// observed by a Reflect query. Populated by + /// `try_reflect_own_addr` on success and read by the `connect` + /// Tauri command to compute the deterministic role for the + /// dual-path QUIC race against `peer_direct_addr`. + own_reflex_addr: Option, } #[tauri::command] @@ -499,6 +658,7 @@ async fn register_signal( ) -> Result { use wzp_proto::SignalMessage; + emit_call_debug(&app, "register_signal:start", serde_json::json!({ "relay": relay })); let addr: std::net::SocketAddr = relay.parse().map_err(|e| format!("bad address: {e}"))?; let _ = rustls::crypto::ring::default_provider().install_default(); @@ -507,25 +667,39 @@ async fn register_signal( let pub_id = seed.derive_identity().public_identity(); let fp = pub_id.fingerprint.to_string(); let identity_pub = *pub_id.signing.as_bytes(); + emit_call_debug(&app, "register_signal:identity_loaded", serde_json::json!({ "fingerprint": fp })); let bind: std::net::SocketAddr = "0.0.0.0:0".parse().unwrap(); let endpoint = wzp_transport::create_endpoint(bind, None).map_err(|e| format!("{e}"))?; + emit_call_debug(&app, "register_signal:endpoint_created", serde_json::json!({ "bind": bind.to_string() })); let conn = wzp_transport::connect(&endpoint, addr, "_signal", wzp_transport::client_config()) - .await.map_err(|e| format!("{e}"))?; + .await + .map_err(|e| { + emit_call_debug(&app, "register_signal:connect_failed", serde_json::json!({ "error": e.to_string() })); + format!("{e}") + })?; let transport = Arc::new(wzp_transport::QuinnTransport::new(conn)); + emit_call_debug(&app, "register_signal:quic_connected", serde_json::json!({ "relay": relay })); transport.send_signal(&SignalMessage::RegisterPresence { identity_pub, signature: vec![], alias: None, }).await.map_err(|e| format!("{e}"))?; + emit_call_debug(&app, "register_signal:register_presence_sent", serde_json::json!({})); match transport.recv_signal().await.map_err(|e| format!("{e}"))? { - Some(SignalMessage::RegisterPresenceAck { success: true, .. }) => {} - _ => return Err("registration failed".into()), + Some(SignalMessage::RegisterPresenceAck { success: true, .. }) => { + emit_call_debug(&app, "register_signal:ack_received", serde_json::json!({})); + } + _ => { + emit_call_debug(&app, "register_signal:ack_failed", serde_json::json!({})); + return Err("registration failed".into()); + } } { let mut sig = state.signal.lock().await; sig.transport = Some(transport.clone()); sig.endpoint = Some(endpoint.clone()); sig.fingerprint = fp.clone(); sig.signal_status = "registered".into(); } tracing::info!(%fp, "signal registered, spawning recv loop"); + emit_call_debug(&app, "register_signal:recv_loop_spawning", serde_json::json!({ "fingerprint": fp })); let signal_state = Arc::clone(&state.signal); let app_clone = app.clone(); tokio::spawn(async move { @@ -533,11 +707,18 @@ async fn register_signal( match transport.recv_signal().await { Ok(Some(SignalMessage::CallRinging { call_id })) => { tracing::info!(%call_id, "signal: CallRinging"); + emit_call_debug(&app_clone, "recv:CallRinging", serde_json::json!({ "call_id": call_id })); let mut sig = signal_state.lock().await; sig.signal_status = "ringing".into(); let _ = app_clone.emit("signal-event", serde_json::json!({"type":"ringing","call_id":call_id})); } - Ok(Some(SignalMessage::DirectCallOffer { caller_fingerprint, caller_alias, call_id, .. })) => { + Ok(Some(SignalMessage::DirectCallOffer { caller_fingerprint, caller_alias, call_id, caller_reflexive_addr, .. })) => { tracing::info!(%call_id, caller = %caller_fingerprint, "signal: DirectCallOffer"); + emit_call_debug(&app_clone, "recv:DirectCallOffer", serde_json::json!({ + "call_id": call_id, + "caller_fp": caller_fingerprint, + "caller_alias": caller_alias, + "caller_reflexive_addr": caller_reflexive_addr, + })); let mut sig = signal_state.lock().await; sig.signal_status = "incoming".into(); sig.incoming_call_id = Some(call_id.clone()); sig.incoming_caller_fp = Some(caller_fingerprint.clone()); sig.incoming_caller_alias = caller_alias.clone(); // Log as a Missed entry up-front. If the user accepts @@ -553,8 +734,13 @@ async fn register_signal( let _ = app_clone.emit("signal-event", serde_json::json!({"type":"incoming","call_id":call_id,"caller_fp":caller_fingerprint,"caller_alias":caller_alias})); let _ = app_clone.emit("history-changed", ()); } - Ok(Some(SignalMessage::DirectCallAnswer { call_id, accept_mode, .. })) => { + Ok(Some(SignalMessage::DirectCallAnswer { call_id, accept_mode, callee_reflexive_addr, .. })) => { tracing::info!(%call_id, ?accept_mode, "signal: DirectCallAnswer (forwarded by relay)"); + emit_call_debug(&app_clone, "recv:DirectCallAnswer", serde_json::json!({ + "call_id": call_id, + "accept_mode": format!("{:?}", accept_mode), + "callee_reflexive_addr": callee_reflexive_addr, + })); } Ok(Some(SignalMessage::CallSetup { call_id, room, relay_addr, peer_direct_addr })) => { // Phase 3: peer_direct_addr carries the OTHER party's @@ -570,6 +756,12 @@ async fn register_signal( peer_direct = ?peer_direct_addr, "signal: CallSetup — emitting setup event to JS" ); + emit_call_debug(&app_clone, "recv:CallSetup", serde_json::json!({ + "call_id": call_id, + "room": room, + "relay_addr": relay_addr, + "peer_direct_addr": peer_direct_addr, + })); let mut sig = signal_state.lock().await; sig.signal_status = "setup".into(); let _ = app_clone.emit( @@ -585,6 +777,7 @@ async fn register_signal( } Ok(Some(SignalMessage::Hangup { reason })) => { tracing::info!(?reason, "signal: Hangup"); + emit_call_debug(&app_clone, "recv:Hangup", serde_json::json!({ "reason": format!("{:?}", reason) })); let mut sig = signal_state.lock().await; sig.signal_status = "registered".into(); sig.incoming_call_id = None; let _ = app_clone.emit("signal-event", serde_json::json!({"type":"hangup"})); } @@ -648,6 +841,8 @@ async fn place_call( ) -> Result<(), String> { use wzp_proto::SignalMessage; + emit_call_debug(&app, "place_call:start", serde_json::json!({ "target_fp": target_fp })); + // Phase 3 hole-punching: query our own reflex addr BEFORE the // offer so we can advertise it. Best-effort — a failed reflect // (old relay, transient error) falls back to `None` which @@ -657,12 +852,15 @@ async fn place_call( // Critical: this call does its own state.signal.lock() usage and // MUST NOT be wrapped in an outer lock, or the recv loop's // ReflectResponse handler will deadlock on the same mutex. + emit_call_debug(&app, "place_call:reflect_query_start", serde_json::json!({})); let state_inner: Arc = (*state).clone(); let own_reflex = try_reflect_own_addr(&state_inner).await.ok().flatten(); if let Some(ref a) = own_reflex { tracing::info!(%a, "place_call: learned own reflex addr for hole-punching advertisement"); + emit_call_debug(&app, "place_call:reflect_query_ok", serde_json::json!({ "addr": a })); } else { tracing::info!("place_call: no reflex addr available, falling back to relay-only"); + emit_call_debug(&app, "place_call:reflect_query_none", serde_json::json!({})); } let sig = state.signal.lock().await; @@ -685,10 +883,18 @@ async fn place_call( ephemeral_pub: [0u8; 32], signature: vec![], supported_profiles: vec![wzp_proto::QualityProfile::GOOD], - caller_reflexive_addr: own_reflex, + caller_reflexive_addr: own_reflex.clone(), }) .await - .map_err(|e| format!("{e}"))?; + .map_err(|e| { + emit_call_debug(&app, "place_call:send_failed", serde_json::json!({ "error": e.to_string() })); + format!("{e}") + })?; + emit_call_debug(&app, "place_call:offer_sent", serde_json::json!({ + "call_id": call_id, + "target_fp": target_fp, + "caller_reflexive_addr": own_reflex, + })); history::log(call_id, target_fp, None, history::CallDirection::Placed); let _ = app.emit("history-changed", ()); Ok(()) @@ -707,6 +913,10 @@ async fn answer_call( 1 => wzp_proto::CallAcceptMode::AcceptTrusted, _ => wzp_proto::CallAcceptMode::AcceptGeneric, }; + emit_call_debug(&app, "answer_call:start", serde_json::json!({ + "call_id": call_id, + "accept_mode": format!("{:?}", accept_mode), + })); // Phase 3 hole-punching: only AcceptTrusted reveals our reflex // addr. Privacy-mode (AcceptGeneric) and Reject explicitly do @@ -717,16 +927,20 @@ async fn answer_call( // the reflect await or the recv loop's ReflectResponse handler // will deadlock on the same mutex. let own_reflex = if accept_mode == wzp_proto::CallAcceptMode::AcceptTrusted { + emit_call_debug(&app, "answer_call:reflect_query_start", serde_json::json!({})); let state_inner: Arc = (*state).clone(); let r = try_reflect_own_addr(&state_inner).await.ok().flatten(); if let Some(ref a) = r { tracing::info!(%call_id, %a, "answer_call: learned own reflex addr for AcceptTrusted"); + emit_call_debug(&app, "answer_call:reflect_query_ok", serde_json::json!({ "addr": a })); } else { tracing::info!(%call_id, "answer_call: no reflex addr for AcceptTrusted, falling back to relay-only"); + emit_call_debug(&app, "answer_call:reflect_query_none", serde_json::json!({})); } r } else { // Reject / AcceptGeneric: keep the IP private. + emit_call_debug(&app, "answer_call:privacy_mode_skip_reflect", serde_json::json!({})); None }; @@ -744,14 +958,20 @@ async fn answer_call( ephemeral_pub: None, signature: None, chosen_profile: Some(wzp_proto::QualityProfile::GOOD), - callee_reflexive_addr: own_reflex, + callee_reflexive_addr: own_reflex.clone(), }) .await .map_err(|e| { tracing::error!(%call_id, error = %e, "answer_call: send_signal failed"); + emit_call_debug(&app, "answer_call:send_failed", serde_json::json!({ "error": e.to_string() })); format!("{e}") })?; tracing::info!(%call_id, "answer_call: DirectCallAnswer sent successfully"); + emit_call_debug(&app, "answer_call:answer_sent", serde_json::json!({ + "call_id": call_id, + "accept_mode": format!("{:?}", accept_mode), + "callee_reflexive_addr": own_reflex, + })); // Upgrade the pending "Missed" entry to "Received" if the user // accepted (mode != Reject). Mode 0 = Reject → leave as Missed. if mode != 0 && history::mark_received_if_pending(&call_id) { @@ -791,7 +1011,17 @@ async fn try_reflect_own_addr( return Ok(None); } match tokio::time::timeout(std::time::Duration::from_millis(1000), rx).await { - Ok(Ok(addr)) => Ok(Some(addr.to_string())), + Ok(Ok(addr)) => { + // Phase 3.5: cache the result on SignalState so the + // `connect` command can read it later for role + // determination without another reflect round-trip. + let s = addr.to_string(); + { + let mut sig = state.signal.lock().await; + sig.own_reflex_addr = Some(s.clone()); + } + Ok(Some(s)) + } Ok(Err(_canceled)) => { tracing::warn!("try_reflect_own_addr: oneshot canceled"); Ok(None) @@ -952,6 +1182,7 @@ pub fn run() { transport: None, endpoint: None, fingerprint: String::new(), signal_status: "idle".into(), incoming_call_id: None, incoming_caller_fp: None, incoming_caller_alias: None, pending_reflect: None, + own_reflex_addr: None, })), }); @@ -1006,6 +1237,7 @@ pub fn run() { set_speakerphone, is_speakerphone_on, get_call_history, get_recent_contacts, clear_call_history, set_dred_verbose_logs, get_dred_verbose_logs, + set_call_debug_logs, get_call_debug_logs, ]) .run(tauri::generate_context!()) .expect("error while running WarzonePhone"); diff --git a/desktop/src/main.ts b/desktop/src/main.ts index 5e90bbf..31e9621 100644 --- a/desktop/src/main.ts +++ b/desktop/src/main.ts @@ -83,6 +83,10 @@ const sRoom = document.getElementById("s-room") as HTMLInputElement; const sAlias = document.getElementById("s-alias") as HTMLInputElement; const sOsAec = document.getElementById("s-os-aec") as HTMLInputElement; const sDredDebug = document.getElementById("s-dred-debug") as HTMLInputElement; +const sCallDebug = document.getElementById("s-call-debug") as HTMLInputElement; +const sCallDebugSection = document.getElementById("s-call-debug-section") as HTMLDivElement; +const sCallDebugLogEl = document.getElementById("s-call-debug-log") as HTMLDivElement; +const sCallDebugClearBtn = document.getElementById("s-call-debug-clear") as HTMLButtonElement; const sReflectedAddr = document.getElementById("s-reflected-addr") as HTMLSpanElement; const sReflectBtn = document.getElementById("s-reflect-btn") as HTMLButtonElement; const sNatType = document.getElementById("s-nat-type") as HTMLSpanElement; @@ -150,6 +154,12 @@ interface Settings { /// reconstruction + classical-PLC logs and adds DRED counters to the /// recv heartbeat. Off in normal mode keeps logcat clean. dredDebugLogs: boolean; + /// Phase 3.5: when true, every step of a call's lifecycle (register, + /// reflect query, offer/answer, relay setup, dual-path race, engine + /// start, media) emits a `call-debug-log` Tauri event that this UI + /// renders into the rolling Debug Log panel in settings. Off in + /// normal mode keeps the GUI quiet but logcat always has a copy. + callDebugLogs: boolean; } function loadSettings(): Settings { @@ -163,6 +173,7 @@ function loadSettings(): Settings { selectedRelay: 0, room: "general", alias: "", osAec: true, agc: true, quality: "auto", recentRooms: [], dredDebugLogs: false, + callDebugLogs: false, }; try { const raw = localStorage.getItem("wzp-settings"); @@ -413,10 +424,52 @@ function renderRecentRooms(rooms: RecentRoom[]) { // ── Init ── applySettings(); setTimeout(pingAllRelays, 300); -// Hydrate the Rust DRED verbose-logs flag from saved settings on boot so -// the choice survives app restarts without needing the user to reopen -// the settings panel. +// Hydrate the Rust DRED + call-debug verbose-logs flags from saved +// settings on boot so the choice survives app restarts without +// needing the user to reopen the settings panel. invoke("set_dred_verbose_logs", { enabled: !!loadSettings().dredDebugLogs }).catch(() => {}); +invoke("set_call_debug_logs", { enabled: !!loadSettings().callDebugLogs }).catch(() => {}); + +// ── Phase 3.5: call-flow debug log rolling buffer ───────────────── +// Backend emits `call-debug-log` events at every step of the call +// lifecycle when the flag is on. We keep a cap-200 ring here and +// render into the Settings panel's Debug Log section. +interface CallDebugEntry { + ts_ms: number; + step: string; + details: any; +} +const CALL_DEBUG_MAX = 200; +const callDebugBuffer: CallDebugEntry[] = []; + +function renderCallDebugLog() { + // Skip the render if the section isn't visible — cheap guard on + // hot path, repainted each time the user opens settings. + if (sCallDebugSection.style.display === "none") return; + const lines = callDebugBuffer.map((e) => { + const iso = new Date(e.ts_ms).toISOString().slice(11, 23); // HH:MM:SS.mmm + const details = e.details && Object.keys(e.details).length > 0 + ? " " + JSON.stringify(e.details) + : ""; + return `${iso} ${e.step}${details}`; + }); + sCallDebugLogEl.textContent = lines.join("\n"); + sCallDebugLogEl.scrollTop = sCallDebugLogEl.scrollHeight; +} + +listen("call-debug-log", (event: any) => { + const entry: CallDebugEntry = event.payload; + callDebugBuffer.push(entry); + if (callDebugBuffer.length > CALL_DEBUG_MAX) { + callDebugBuffer.shift(); + } + renderCallDebugLog(); +}); + +sCallDebugClearBtn.addEventListener("click", () => { + callDebugBuffer.length = 0; + sCallDebugLogEl.textContent = ""; +}); // Load fingerprint + alias + git hash + render identicon interface AppInfo { git_hash: string; alias: string; fingerprint: string; data_dir: string } @@ -730,6 +783,11 @@ function openSettings() { const s = loadSettings(); sRoom.value = s.room; sAlias.value = s.alias; sOsAec.checked = s.osAec; sDredDebug.checked = !!s.dredDebugLogs; + sCallDebug.checked = !!s.callDebugLogs; + // Show the debug-log panel only when the user has the flag on — + // keeps the settings panel short in normal use. + sCallDebugSection.style.display = s.callDebugLogs ? "" : "none"; + renderCallDebugLog(); const qi = qualityToIndex(s.quality || "auto"); sQuality.value = String(qi); updateQualityUI(qi); @@ -874,10 +932,14 @@ settingsSave.addEventListener("click", () => { s.room = sRoom.value; s.alias = sAlias.value; s.osAec = sOsAec.checked; s.quality = QUALITY_STEPS[parseInt(sQuality.value)] || "auto"; s.dredDebugLogs = sDredDebug.checked; + s.callDebugLogs = sCallDebug.checked; saveSettingsObj(s); - // Push the new flag to the Rust side immediately so the next encoded - // frame already honors it without waiting for an app restart. + // Push the new flags to the Rust side immediately so the next + // frame / call already honors them without waiting for a restart. invoke("set_dred_verbose_logs", { enabled: s.dredDebugLogs }).catch(() => {}); + invoke("set_call_debug_logs", { enabled: s.callDebugLogs }).catch(() => {}); + // Reveal or hide the debug-log panel based on the new setting. + sCallDebugSection.style.display = s.callDebugLogs ? "" : "none"; roomInput.value = s.room; aliasInput.value = s.alias; osAecCheckbox.checked = s.osAec; renderRecentRooms(s.recentRooms); closeSettings();