start tracking path events

Author: dignifiedquire

Cargo.lock

@@ -51,6 +51,6 @@ netwatch = { git = "https://github.com/n0-computer/net-tools", branch = "feat-mu
 # iroh-quinn-proto = { path = "../iroh-quinn/quinn-proto" }
 # iroh-quinn-udp = { path = "../iroh-quinn/quinn-udp" }
 
-# iroh-quinn = { git = "https://github.com//n0-computer/quinn", branch = "multipath-misc" }
-# iroh-quinn-proto = { git = "https://github.com//n0-computer/quinn", branch = "multipath-misc" }
-# iroh-quinn-udp = { git = "https://github.com//n0-computer/quinn", branch = "multipath-misc" }
+# iroh-quinn = { git = "https://github.com//n0-computer/quinn", branch = "flub/quinn-path-events-status" }
+# iroh-quinn-proto = { git = "https://github.com//n0-computer/quinn", branch = "flub/quinn-path-events-status" }
+# iroh-quinn-udp = { git = "https://github.com//n0-computer/quinn", branch = "flub/quinn-path-events-status" }

Cargo.toml

@@ -1768,13 +1768,20 @@ impl Future for Connecting {
                 let conn = Connection { inner };
 
                 // Grab the remote identity and register this connection
-
                 if let Some(remote) = *this.remote_node_id {
                     let weak_handle = conn.inner.weak_handle();
-                    this.ep.msock.register_connection(remote, weak_handle);
+                    let path_events = conn.inner.path_events();
+                    this.ep
+                        .msock
+                        .register_connection(remote, weak_handle, path_events);
                 } else if let Ok(remote) = conn.remote_node_id() {
                     let weak_handle = conn.inner.weak_handle();
-                    this.ep.msock.register_connection(remote, weak_handle);
+                    let path_events = conn.inner.path_events();
+                    this.ep
+                        .msock
+                        .register_connection(remote, weak_handle, path_events);
+                } else {
+                    warn!("unable to determine node id for the remote");
                 }
 
                 try_send_rtt_msg(&conn, this.ep, *this.remote_node_id);

iroh/src/endpoint.rs

@@ -43,6 +43,7 @@ use netwatch::netmon;
 #[cfg(not(wasm_browser))]
 use netwatch::{ip::LocalAddresses, UdpSocket};
 use quinn::{AsyncUdpSocket, ServerConfig, WeakConnectionHandle};
+use quinn_proto::PathEvent;
 use rand::Rng;
 use smallvec::SmallVec;
 use snafu::{ResultExt, Snafu};
@@ -293,8 +294,29 @@ impl MagicSock {
         self.local_addrs_watch.get().expect("disconnected")
     }
 
-    pub(crate) fn register_connection(&self, remote: NodeId, conn: WeakConnectionHandle) {
+    pub(crate) fn register_connection(
+        &self,
+        remote: NodeId,
+        conn: WeakConnectionHandle,
+        mut path_events: tokio::sync::broadcast::Receiver<PathEvent>,
+    ) {
         self.connection_map.insert(remote, conn);
+
+        // TODO: track task
+        // TODO: find a good home for this
+        task::spawn(async move {
+            loop {
+                match path_events.recv().await {
+                    Ok(event) => {
+                        info!(remote = %remote, "path event: {:?}", event);
+                    }
+                    Err(tokio::sync::broadcast::error::RecvError::Lagged(_)) => {
+                        warn!("lagged path events");
+                    }
+                    Err(tokio::sync::broadcast::error::RecvError::Closed) => break,
+                }
+            }
+        });
     }
 
     #[cfg(not(wasm_browser))]

iroh/src/magicsock.rs

@@ -533,12 +533,6 @@ impl NodeState {
                 .replace(now);
         }
 
-        // Zero out all the last_ping times to force send_pings to send new ones, even if
-        // it's been less than 5 seconds ago.  Also clear pongs for direct addresses not
-        // included in the updated set.
-        for (_ipp, st) in self.udp_paths.paths.iter_mut() {
-            st.last_ping = None;
-        }
         // Clear trust on our best_addr if it is not included in the updated set.  Also
         // clear the last call-me-maybe send time so we will send one again.
         if let Some(addr) = self.udp_paths.best_addr.addr() {
@@ -594,21 +588,6 @@ impl NodeState {
         self.last_used = Some(now);
     }
 
-    pub(super) fn last_ping(&self, addr: &SendAddr) -> Option<Instant> {
-        match addr {
-            SendAddr::Udp(addr) => self
-                .udp_paths
-                .paths
-                .get(&(*addr).into())
-                .and_then(|ep| ep.last_ping),
-            SendAddr::Relay(url) => self
-                .relay_url
-                .as_ref()
-                .filter(|(home_url, _state)| home_url == url)
-                .and_then(|(_home_url, state)| state.last_ping),
-        }
-    }
-
     /// Checks if this `Endpoint` is currently actively being used.
     pub(super) fn is_active(&self, now: &Instant) -> bool {
         match self.last_used {

iroh/src/magicsock/node_map/node_state.rs

@@ -14,12 +14,6 @@ use super::{
 };
 use crate::disco::SendAddr;
 
-/// The minimum time between pings to an endpoint.
-///
-/// Except in the case of CallMeMaybe frames resetting the counter, as the first pings
-/// likely didn't through the firewall.
-const DISCO_PING_INTERVAL: Duration = Duration::from_secs(5);
-
 /// State about a particular path to another [`NodeState`].
 ///
 /// This state is used for both the relay path and any direct UDP paths.
@@ -31,13 +25,6 @@ pub(super) struct PathState {
     node_id: NodeId,
     /// The path this applies for.
     path: SendAddr,
-    /// The last (outgoing) ping time.
-    pub(super) last_ping: Option<Instant>,
-
-    /// If non-zero, means that this was an endpoint that we learned about at runtime (from an
-    /// incoming ping). If so, we keep the time updated and use it to discard old candidates.
-    // NOTE: tx_id Originally added in tailscale due to <https://github.com/tailscale/tailscale/issues/7078>.
-    last_got_ping: Option<(Instant, stun_rs::TransactionId)>,
 
     /// The time this endpoint was last advertised via a call-me-maybe DISCO message.
     pub(super) call_me_maybe_time: Option<Instant>,
@@ -61,8 +48,6 @@ impl PathState {
         Self {
             node_id,
             path,
-            last_ping: None,
-            last_got_ping: None,
             call_me_maybe_time: None,
             last_payload_msg: None,
             sources,
@@ -87,8 +72,6 @@ impl PathState {
         PathState {
             node_id,
             path,
-            last_ping: None,
-            last_got_ping: None,
             call_me_maybe_time: None,
             last_payload_msg: Some(now),
             sources,
@@ -109,11 +92,6 @@ impl PathState {
             .unwrap_or(false)
     }
 
-    /// Returns the instant the last incoming ping was received.
-    pub(super) fn last_incoming_ping(&self) -> Option<&Instant> {
-        self.last_got_ping.as_ref().map(|(time, _tx_id)| time)
-    }
-
     /// Reports the last instant this path was considered alive.
     ///
     /// Alive means the path is considered in use by the remote endpoint.  Either because we
@@ -130,15 +108,13 @@ impl PathState {
             .as_ref()
             .into_iter()
             .chain(self.call_me_maybe_time.as_ref())
-            .chain(self.last_incoming_ping())
             .max()
             .copied()
     }
 
     /// The last control or DISCO message **about** this path.
     ///
     /// This is the most recent instant among:
-    /// - when last pong was received.
     /// - when this path was last advertised in a received CallMeMaybe message.
     /// - when the last ping from them was received.
     ///
@@ -149,41 +125,18 @@ impl PathState {
             .call_me_maybe_time
             .as_ref()
             .map(|call_me| (*call_me, ControlMsg::CallMeMaybe));
-        let last_ping = self
-            .last_incoming_ping()
-            .map(|ping| (*ping, ControlMsg::Ping));
 
         last_call_me_maybe
             .into_iter()
-            .chain(last_ping)
             .max_by_key(|(instant, _kind)| *instant)
             .map(|(instant, kind)| (now.duration_since(instant), kind))
     }
 
-    pub(super) fn needs_ping(&self, now: &Instant) -> bool {
-        match self.last_ping {
-            None => true,
-            Some(last_ping) => {
-                let elapsed = now.duration_since(last_ping);
-
-                // TODO: remove!
-                // This logs "ping is too new" for each send whenever the endpoint does *not* need
-                // a ping. Pretty sure this is not a useful log, but maybe there was a reason?
-                // if !needs_ping {
-                //     debug!("ping is too new: {}ms", elapsed.as_millis());
-                // }
-                elapsed > DISCO_PING_INTERVAL
-            }
-        }
-    }
-
     pub(super) fn add_source(&mut self, source: Source, now: Instant) {
         self.sources.insert(source, now);
     }
 
     pub(super) fn clear(&mut self) {
-        self.last_ping = None;
-        self.last_got_ping = None;
         self.call_me_maybe_time = None;
     }
 
@@ -192,12 +145,6 @@ impl PathState {
         if self.is_active() {
             write!(w, "active ")?;
         }
-        if let Some(when) = self.last_incoming_ping() {
-            write!(w, "ping-received({:?} ago) ", when.elapsed())?;
-        }
-        if let Some(ref when) = self.last_ping {
-            write!(w, "ping-sent({:?} ago) ", when.elapsed())?;
-        }
         if let Some(last_source) = self.sources.iter().max_by_key(|&(_, instant)| instant) {
             write!(
                 w,