Support RUST_LOG, enable UPnP portmapper and add NAT traversal logging
Previously, `tsunagi-cli` configured clap with a fixed default_value and `env = "TSUNAGI_LOG"`, which caused `RUST_LOG` to be completely ignored. In addition, `iroh` was built with `default-features = false` and lacked the `"portmapper"` feature, which caused it to compile a stub client and disable UPnP-IGD, PCP, and NAT-PMP port mapping. Furthermore, there was no visibility into STUN address discovery, UPnP port mapping status, or QUIC transmission path switching (hole punch vs relay). Key improvements: - Enable the `"portmapper"` feature on `iroh` in workspace Cargo.toml, pulling in `portmapper` and `igd-next` to actively request port mappings on local routers. - In `crates/tsunagi-cli/src/main.rs`, support `RUST_LOG` with fallback precedence (`--log` > `TSUNAGI_LOG` > `RUST_LOG` > default filter). When debug or trace filtering is active, automatically enable `.with_target(true)` so users can see which subsystem emitted the log (e.g., portmapper, iroh::magicsock, tsunagi::net). - In `crates/tsunagi/src/net.rs`, monitor `endpoint.watch_addr()` and `endpoint.home_relay_status()`. Emit `DEBUG` logs for local socket binding, discovered STUN reflexive/UPnP addresses, and relay connections. If no direct addresses are discovered after probe grace, emit a concise `WARN`. - In `crates/tsunagi/src/agent/session.rs`, monitor connection `path_events()` to log when transmission paths are opened, closed, or selected (switching between relay and direct hole-punched paths), with bounded task winding down on shutdown. Validation on Linux: - cargo fmt --all -- --check passed. - cargo clippy --locked --workspace --all-targets -- -D warnings passed. - cargo test --locked --workspace --all-targets passed (349 tests passed). - Live verification with `RUST_LOG=debug` confirmed SSDP broadcast to 239.255.255.250:1900, portmapper logs, STUN QAD discovery, and clean relay shutdown.
This commit is contained in:
1 parent
c0a76f1942
commit
192ab25bbd
6 files changed
+262
-12
No files matched your search
@@ -33,13 +33,10 @@ use tsunagi_wg_quic::{WireguardConfig, WireguardPlugin};
|
||||
#[command(name = "tsunagi", version, about, long_about = None)]
|
||||
struct Cli {
|
||||
/// Log filter, for example `info` or `tsunagi=debug`.
|
||||
#[arg(
|
||||
long,
|
||||
global = true,
|
||||
env = "TSUNAGI_LOG",
|
||||
default_value = "info,iroh=warn,quinn=warn,rustls=warn,boringtun=warn,mainline=off"
|
||||
)]
|
||||
log: String,
|
||||
///
|
||||
/// Can also be set via the `TSUNAGI_LOG` or `RUST_LOG` environment variables.
|
||||
#[arg(long, global = true)]
|
||||
log: Option<String>,
|
||||
|
||||
#[command(subcommand)]
|
||||
command: Command,
|
||||
@@ -696,9 +693,19 @@ fn parse_peer(text: &str) -> Result<EndpointAddr, String> {
|
||||
fn main() -> std::process::ExitCode {
|
||||
let cli = Cli::parse();
|
||||
|
||||
let log_filter = cli
|
||||
.log
|
||||
.or_else(|| std::env::var("TSUNAGI_LOG").ok())
|
||||
.or_else(|| std::env::var("RUST_LOG").ok())
|
||||
.unwrap_or_else(|| {
|
||||
"info,iroh=warn,quinn=warn,rustls=warn,boringtun=warn,mainline=off".to_string()
|
||||
});
|
||||
|
||||
let is_debug = log_filter.contains("debug") || log_filter.contains("trace");
|
||||
|
||||
tracing_subscriber::fmt()
|
||||
.with_env_filter(tracing_subscriber::EnvFilter::new(&cli.log))
|
||||
.with_target(false)
|
||||
.with_env_filter(tracing_subscriber::EnvFilter::new(&log_filter))
|
||||
.with_target(is_debug)
|
||||
.compact()
|
||||
.with_writer(std::io::stderr)
|
||||
.init();
|
||||
|
||||
@@ -38,6 +38,7 @@ iroh.workspace = true
|
||||
# `net` for the local control interface: a Unix socket on Unix, a named pipe
|
||||
# on Windows. Both live behind the same `net` feature.
|
||||
tokio = { workspace = true, features = ["net"] }
|
||||
tokio-stream = "0.1"
|
||||
serde.workspace = true
|
||||
postcard.workspace = true
|
||||
bytes.workspace = true
|
||||
|
||||
@@ -80,11 +80,12 @@ pub(crate) struct Session {
|
||||
pub(crate) bytes_received: u64,
|
||||
reader: JoinHandle<()>,
|
||||
writer: JoinHandle<()>,
|
||||
path_monitor: JoinHandle<()>,
|
||||
shutdown: Shutdown,
|
||||
}
|
||||
|
||||
impl Session {
|
||||
/// Signals both tasks to stop and waits for them, with a bounded grace
|
||||
/// Signals all tasks to stop and waits for them, with a bounded grace
|
||||
/// period.
|
||||
///
|
||||
/// A peer that stops reading must not be able to hold up shutdown, so the
|
||||
@@ -94,6 +95,7 @@ impl Session {
|
||||
conn,
|
||||
reader,
|
||||
writer,
|
||||
path_monitor,
|
||||
shutdown,
|
||||
..
|
||||
} = self;
|
||||
@@ -103,23 +105,27 @@ impl Session {
|
||||
|
||||
let reader_abort = reader.abort_handle();
|
||||
let writer_abort = writer.abort_handle();
|
||||
let path_abort = path_monitor.abort_handle();
|
||||
let joined = tokio::time::timeout(STOP_GRACE, async move {
|
||||
let _ = reader.await;
|
||||
let _ = writer.await;
|
||||
let _ = path_monitor.await;
|
||||
})
|
||||
.await;
|
||||
if joined.is_err() {
|
||||
tracing::debug!("session tasks did not wind down in time; aborting them");
|
||||
reader_abort.abort();
|
||||
writer_abort.abort();
|
||||
path_abort.abort();
|
||||
}
|
||||
}
|
||||
|
||||
/// Aborts both tasks without waiting. Used on replacement.
|
||||
/// Aborts all tasks without waiting. Used on replacement.
|
||||
pub(crate) fn abort(&self) {
|
||||
self.shutdown.trigger();
|
||||
self.reader.abort();
|
||||
self.writer.abort();
|
||||
self.path_monitor.abort();
|
||||
}
|
||||
}
|
||||
|
||||
@@ -155,6 +161,52 @@ pub(crate) fn spawn(
|
||||
parent_shutdown.clone(),
|
||||
));
|
||||
|
||||
let path_conn = conn.clone();
|
||||
let path_shutdown = shutdown.clone();
|
||||
let path_parent = parent_shutdown.clone();
|
||||
let path_monitor = tokio::spawn(async move {
|
||||
use tokio_stream::StreamExt;
|
||||
let mut events = path_conn.path_events();
|
||||
loop {
|
||||
tokio::select! {
|
||||
biased;
|
||||
_ = path_shutdown.wait() => break,
|
||||
_ = path_parent.wait() => break,
|
||||
ev = events.next() => {
|
||||
match ev {
|
||||
Some(iroh::endpoint::PathEvent::Selected { remote_addr, local_addr, .. }) => {
|
||||
tracing::debug!(
|
||||
peer = %peer.fmt_short(),
|
||||
remote = %remote_addr,
|
||||
local = ?local_addr,
|
||||
"Connection path selected (direct / relay / hole punch switch)"
|
||||
);
|
||||
}
|
||||
Some(iroh::endpoint::PathEvent::Opened { remote_addr, .. }) => {
|
||||
tracing::debug!(
|
||||
peer = %peer.fmt_short(),
|
||||
remote = %remote_addr,
|
||||
"Network path opened to peer"
|
||||
);
|
||||
}
|
||||
Some(iroh::endpoint::PathEvent::Closed { remote_addr, .. }) => {
|
||||
tracing::debug!(
|
||||
peer = %peer.fmt_short(),
|
||||
remote = %remote_addr,
|
||||
"Network path closed for peer"
|
||||
);
|
||||
}
|
||||
Some(iroh::endpoint::PathEvent::Lagged { missed, .. }) => {
|
||||
tracing::trace!(peer = %peer.fmt_short(), missed, "Path events lagged");
|
||||
}
|
||||
Some(_) => {}
|
||||
None => break,
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
});
|
||||
|
||||
let reader = tokio::spawn(reader_task(
|
||||
id,
|
||||
network_id,
|
||||
@@ -182,6 +234,7 @@ pub(crate) fn spawn(
|
||||
bytes_received: 0,
|
||||
reader,
|
||||
writer,
|
||||
path_monitor,
|
||||
shutdown,
|
||||
}
|
||||
}
|
||||
|
||||
@@ -259,6 +259,91 @@ impl EndpointAdapter {
|
||||
.await
|
||||
.map_err(|err| Error::Endpoint(format!("cannot bind endpoint: {err}")))?;
|
||||
|
||||
tracing::debug!(
|
||||
endpoint = %endpoint.id().fmt_short(),
|
||||
bound_sockets = ?endpoint.bound_sockets(),
|
||||
"iroh endpoint bound locally"
|
||||
);
|
||||
|
||||
let ep_id = endpoint.id();
|
||||
let mut addr_watcher = endpoint.watch_addr();
|
||||
let mut relay_watcher = endpoint.home_relay_status();
|
||||
let close_token = endpoint.clone();
|
||||
tokio::spawn(async move {
|
||||
use iroh::Watcher;
|
||||
let mut last_addrs: Vec<SocketAddr> = Vec::new();
|
||||
let mut last_relays: Vec<String> = Vec::new();
|
||||
|
||||
let warn_timer = tokio::time::sleep(Duration::from_secs(12));
|
||||
tokio::pin!(warn_timer);
|
||||
let mut warned = false;
|
||||
|
||||
loop {
|
||||
tokio::select! {
|
||||
biased;
|
||||
_ = close_token.closed() => {
|
||||
break;
|
||||
}
|
||||
() = &mut warn_timer, if !warned => {
|
||||
warned = true;
|
||||
if last_addrs.is_empty() && !last_relays.is_empty() {
|
||||
tracing::warn!(
|
||||
endpoint = %ep_id.fmt_short(),
|
||||
relays = ?last_relays,
|
||||
"No direct reflexive or UPnP addresses discovered after probe; communications will rely on relay servers"
|
||||
);
|
||||
} else if last_addrs.is_empty() && last_relays.is_empty() {
|
||||
tracing::warn!(
|
||||
endpoint = %ep_id.fmt_short(),
|
||||
"No reachability discovered (neither direct reflexive/UPnP addresses nor relay servers available)"
|
||||
);
|
||||
}
|
||||
}
|
||||
res = addr_watcher.updated() => {
|
||||
let addr = match res {
|
||||
Ok(a) => a,
|
||||
Err(_) => break,
|
||||
};
|
||||
let addrs: Vec<SocketAddr> = addr.ip_addrs().copied().collect();
|
||||
let relays: Vec<String> = addr.relay_urls().map(|u| u.to_string()).collect();
|
||||
|
||||
if addrs != last_addrs || relays != last_relays {
|
||||
tracing::debug!(
|
||||
endpoint = %ep_id.fmt_short(),
|
||||
direct_addrs = ?addrs,
|
||||
relays = ?relays,
|
||||
"Discovered endpoint reachability (STUN/UPnP/local/relay)"
|
||||
);
|
||||
last_addrs = addrs;
|
||||
last_relays = relays;
|
||||
}
|
||||
}
|
||||
res = relay_watcher.updated() => {
|
||||
let relays = match res {
|
||||
Ok(r) => r,
|
||||
Err(_) => break,
|
||||
};
|
||||
for relay in &relays {
|
||||
if relay.is_connected() {
|
||||
tracing::debug!(
|
||||
endpoint = %ep_id.fmt_short(),
|
||||
relay = %relay.url(),
|
||||
"Connected to home relay server"
|
||||
);
|
||||
} else if let Some(err) = relay.last_error() {
|
||||
tracing::debug!(
|
||||
endpoint = %ep_id.fmt_short(),
|
||||
relay = %relay.url(),
|
||||
error = %err,
|
||||
"Relay connection attempt failed"
|
||||
);
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
});
|
||||
|
||||
Ok(Self { endpoint })
|
||||
}
|
||||
|
||||
|
||||
Reference in new issue
Block a user