manawenuz/wz-phone
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

feat(p2p): Phase 3.5 dual-path QUIC race + GUI call-flow debug logs

Browse Source 
Two features in one commit because they ship and test together:
Phase 3.5 closes the hole-punching loop and the call-flow debug
logs give the user live visibility into every step of a call so
real-hardware testing of the new P2P path is debuggable.

## Phase 3.5 — dual-path QUIC connect race

Completes the hole-punching work Phase 3 scaffolded. On receiving
a CallSetup with peer_direct_addr, the client now actually races a
direct QUIC handshake against the relay dial and uses whichever
completes first. Symmetric role assignment avoids the two-conns-
per-call problem:

- Both peers compare `own_reflex_addr` vs `peer_reflex_addr`
  lexicographically.
- Smaller addr → **Acceptor** (A-role): builds a server-capable
  dual endpoint, awaits an incoming QUIC session. Does NOT dial.
- Larger addr → **Dialer** (D-role): builds a client-only
  endpoint, dials the peer's addr with `call-<id>` SNI. Does NOT
  listen.
- Both sides always dial the relay in parallel as fallback.
- `tokio::select!` with `biased` preference for direct, `tokio::pin!`
  so each branch can await the losing opposite as fallback.
- Direct timeout 2s, relay fallback timeout 5s (so 7s worst case
  from CallSetup to "no media path" error).

New crate module `wzp_client::dual_path::{race, WinningPath}`
(moved here from desktop/src-tauri so it's testable from a
workspace test). `determine_role` in `wzp_client::reflect` is
pure-function and unit-tested.

### CallEngine integration
- New `pre_connected_transport: Option<Arc<QuinnTransport>>` arg
  on both android + desktop `CallEngine::start` branches. Skips
  the internal wzp_transport::connect step when Some. Backward-
  compat: None keeps Phase 0 relay-only behavior.
- `connect` Tauri command reads own_reflex_addr from SignalState,
  computes role, runs the race, passes the winning transport
  into CallEngine. If ANY input is missing (no peer addr, no own
  addr, equal addrs), falls back to classic relay path —
  identical to pre-Phase-3.5 behavior.

### Tests (9 new, all passing)
- 6 unit tests for `determine_role` truth table in
  `wzp-client/src/reflect.rs` (smaller=Acceptor, larger=Dialer,
  port-only diff, equal, missing-side, symmetry)
- 3 integration tests in `crates/wzp-client/tests/dual_path.rs`:
    * `dual_path_direct_wins_on_loopback` — two-endpoint test
      rig, Dialer wins direct path vs loopback mock relay
    * `dual_path_relay_wins_when_direct_is_dead` — dead peer
      port, 2s direct timeout, relay fallback wins
    * `dual_path_errors_cleanly_when_both_paths_dead` — <10s
      error, no hang

## GUI call-flow debug logs

Runtime-toggled structured events at every step of a call so the
user can see where a call progressed or stalled on real hardware.
Modeled on the existing DRED_VERBOSE_LOGS pattern.

### Rust side
- `static CALL_DEBUG_LOGS: AtomicBool` + `emit_call_debug(&app,
  step, details)` helper. Always logs via `tracing::info!`
  (logcat always has a copy); GUI Tauri `call-debug-log` event
  only fires when the flag is on.
- Tauri commands `set_call_debug_logs` / `get_call_debug_logs`.

### Instrumented steps (24 emit_call_debug sites)
- `register_signal`: start, identity loaded, endpoint created,
  connect failed/ok, RegisterPresence sent, ack received/failed,
  recv loop spawning
- Recv loop: CallRinging, DirectCallOffer (w/ caller_reflexive_addr),
  DirectCallAnswer (w/ callee_reflexive_addr), CallSetup (w/
  peer_direct_addr), Hangup
- `place_call`: start, reflect query start/ok/none, offer sent,
  send failed
- `answer_call`: start, reflect query start/ok/none or privacy
  skip, answer sent, send failed
- `connect`: start, dual_path_race_start (w/ role), won (w/
  path), failed, skipped (w/ reasons), call_engine_starting/
  started/failed

### JS side
- New `callDebugLogs: boolean` field on Settings type.
- Boot-time hydrate of the Rust flag from localStorage so the
  choice survives restarts (like `dredDebugLogs`).
- Settings panel: new "Call flow debug logs" checkbox alongside
  the DRED toggle.
- New "Call Debug Log" section that ONLY shows when the flag is
  on. Rolling in-memory buffer of the last 200 events, rendered
  as monospace `HH:MM:SS.mmm step {details}` lines with auto-
  scroll and a Clear button.
- `listen("call-debug-log", ...)` subscribed at app startup,
  appends to the buffer, re-renders on every event.

Full workspace test goes from 404 → 413 passing. Clippy clean
on touched crates.

PRD: .taskmaster/docs/prd_phase35_dual_path_race.txt
Tasks: 61-69 all completed

Next: APK + desktop build carrying everything — Phase 2 NAT
detect, Phase 3 advertising, Phase 3.5 dual-path + call debug
logs, plus the earlier Android first-join diagnostics — so the
user can validate the P2P path on real hardware with live
per-step visibility into where any failures happen.

Co-Authored-By: Claude Opus 4.6 (1M context) <noreply@anthropic.com>
This commit is contained in:
Siavash Sameni
2026-04-11 14:06:44 +04:00
parent 39277bf3a0
commit 59ce52f8e8
8 changed files with 920 additions and 73 deletions
Download Patch File Download Diff File Expand all files Collapse all files

14
desktop/index.html
View File

@@ -173,6 +173,20 @@
<input id="s-dred-debug" type="checkbox" />
DRED debug logs (verbose, dev only)
</label>
<label class="checkbox">
<input id="s-call-debug" type="checkbox" />
Call flow debug logs (trace every step of a call)
</label>
</div>
<div class="settings-section" id="s-call-debug-section" style="display:none">
<h3>Call Debug Log</h3>
<div id="s-call-debug-log" style="max-height:220px;overflow-y:auto;background:#0a0a0a;color:#e0e0e0;font-family:ui-monospace,Menlo,Monaco,'Courier New',monospace;font-size:10px;padding:6px;border-radius:4px;line-height:1.4;white-space:pre-wrap"></div>
<button id="s-call-debug-clear" class="secondary-btn" style="margin-top:6px">Clear log</button>
<small style="color:var(--text-dim);display:block;margin-top:4px">
Rolling buffer of the last 200 call-flow events. Turned off by
default — the GUI overlay only populates when the checkbox above
is on, but logcat (adb) always keeps a copy regardless.
</small>
</div>
<div class="settings-section">
<h3>Identity</h3>

135
desktop/src-tauri/src/engine.rs
View File

@@ -297,6 +297,11 @@ impl CallEngine {
_os_aec: bool,
quality: String,
reuse_endpoint: Option<wzp_transport::Endpoint>,
// 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<Arc<wzp_transport::QuinnTransport>>,
event_cb: F,
) -> Result<Self, anyhow::Error>
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<wzp_transport::Endpoint>,
// 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<Arc<wzp_transport::QuinnTransport>>,
event_cb: F,
) -> Result<Self, anyhow::Error>
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(

266
desktop/src-tauri/src/lib.rs
View File

@@ -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<PingResult, String> {
@@ -271,28 +334,114 @@ async fn connect(
#[allow(non_snake_case)]
peer_direct_addr: Option<String>,
) -> Result<String, String> {
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<std::net::SocketAddr> = peer_direct_addr
.as_deref()
.and_then(|s| s.parse().ok());
let relay_addr_parsed: Option<std::net::SocketAddr> = 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<Arc<wzp_transport::QuinnTransport>> =
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<tokio::sync::oneshot::Sender<std::net::SocketAddr>>,
/// 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<String>,
}
#[tauri::command]
@@ -499,6 +658,7 @@ async fn register_signal(
) -> Result<String, String> {
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<AppState> = (*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<AppState> = (*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");

72
desktop/src/main.ts
View File

@@ -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();