From 76f81945109608c6bb13275b4092cadaca72568c Mon Sep 17 00:00:00 2001 From: Johnathan Corgan Date: Sun, 4 Oct 2026 22:19:50 +0000 Subject: [PATCH 1/3] Stop the receive loop dialing when it answers a handshake, and serve live transport counters When a TCP connection closed before the node answered a handshake or rekey that arrived on it, the reply went through connect-on-send. For an inbound connection that dials the peer's ephemeral port, usually behind NAT, and the receive loop waited out the whole connect timeout (5 s on TCP, 120 s on Tor) before handling anything else. A run of these kept the packet channel full, so UDP frames backed up, the tick stopped running, and peers dropped away (#176). A new transport send, send_existing, uses only an existing connection, or a background connect that has finished, and otherwise fails at once. Every send the node makes from the receive loop now uses it: the msg2 and its resends, the rekey msg2 and its resend, the rekey msg1 and its resend, the msg1 resend on an outbound handshake, the dial's stored msg1, and the encrypted link send. The tick and dial-path sends start a background connect first, but only toward an address this node dialed, never toward an inbound peer's source port. No node code calls the dialing send any more. A peer that redials over TCP at the same epoch while the node still holds its old connection is answered on the connection its msg1 arrived on, when the established one has gone and both are on the same transport, as 0.5.2 did. A msg1 on a connectionless transport is still answered only on the established link. The transport counters were wrong or frozen when they were needed most: fipsctl show transports served them from a copy only the tick refreshes, so they stopped moving when the tick starved. They are now read live. Datagrams on the per-peer connected UDP sockets, encrypt-worker UDP sends and background connect failures are now counted, and the kernel_drops and connect_refused docs say what they cover. Tests in src/node/tests/rx_stall.rs reproduce the stall against a listener whose accept queue is full (backlog 1, filled until a connect times out, which holds on Linux, macOS and the BSDs), so connects time out rather than being refused, and assert it cannot happen: each dead-link reply and tick send returns within 250 ms with no connect attempt, a UDP handshake behind dead TCP replies is answered at once, the tick keeps running, and live connections still get their replies. Each site was checked by reverting it to the dialing send: its test went red at about the 5 s connect timeout with one connect timeout counted. The dial-permission check also has a plain unit test with no runtime or sockets, and the executor's doc names the sends it now makes. --- src/control/queries.rs | 10 +- src/control/read_handle.rs | 5 +- src/control/snapshot.rs | 18 +- src/node/dataplane/connected_udp.rs | 10 +- src/node/dataplane/peer_actions.rs | 18 +- src/node/encrypt_worker.rs | 348 +++++- src/node/handlers/handshake.rs | 128 ++- src/node/handlers/rekey.rs | 21 +- src/node/handlers/session.rs | 2 + src/node/handlers/timeout.rs | 5 +- src/node/lifecycle/mod.rs | 10 +- src/node/mod.rs | 93 +- src/node/tests/connected_udp.rs | 238 ++++ src/node/tests/control.rs | 98 ++ src/node/tests/mod.rs | 1 + src/node/tests/rx_stall.rs | 1310 +++++++++++++++++++++++ src/node/tests/session.rs | 2 +- src/node/tests/tcp.rs | 154 +++ src/testutil.rs | 97 ++ src/transport/mod.rs | 218 +++- src/transport/nym/mod.rs | 302 +++++- src/transport/socks5/mod.rs | 4 +- src/transport/socks5/pool.rs | 44 + src/transport/tcp/mod.rs | 427 +++++++- src/transport/tcp/pool.rs | 7 + src/transport/tcp/stats.rs | 10 +- src/transport/tor/mod.rs | 336 +++++- src/transport/udp/io/connected/drain.rs | 27 +- src/transport/udp/mod.rs | 2 +- src/transport/udp/stats.rs | 26 +- 30 files changed, 3703 insertions(+), 268 deletions(-) create mode 100644 src/node/tests/rx_stall.rs diff --git a/src/control/queries.rs b/src/control/queries.rs index 53420106..c366e328 100644 --- a/src/control/queries.rs +++ b/src/control/queries.rs @@ -1406,9 +1406,11 @@ pub fn show_transports(node: &Node) -> Value { /// Off-loop variant of [`show_transports`]: renders from the tick-published /// [`EntitySnapshot`](super::snapshot::EntitySnapshot) transport table. The -/// `stats` and `tor_monitoring` blocks are already-projected `serde_json::Value` -/// data captured at publish time. Output is byte-identical to -/// [`show_transports`]. +/// `tor_monitoring` block is already-projected `serde_json::Value` data +/// captured at publish time. The `stats` block is read now from the +/// transport's shared counters, as `show_status` reads `forwarding`, so it is +/// current even when the tick has not run since the counters moved. Output +/// is byte-identical to [`show_transports`]. pub(crate) fn show_transports_from_handle(handle: &super::read_handle::ControlReadHandle) -> Value { let entities = handle.entities(); let transports: Vec = entities @@ -1439,7 +1441,7 @@ pub(crate) fn show_transports_from_handle(handle: &super::read_handle::ControlRe t_json["tor_monitoring"] = monitoring.clone(); } - t_json["stats"] = t.stats.clone(); + t_json["stats"] = t.stats.to_json(); t_json }) diff --git a/src/control/read_handle.rs b/src/control/read_handle.rs index ad4d1f80..4d46ebe2 100644 --- a/src/control/read_handle.rs +++ b/src/control/read_handle.rs @@ -27,7 +27,10 @@ //! //! A projection is a point-in-time copy, not a live view. The entity tables in //! particular are mutated on the packet path between ticks, so a reader sees -//! the state as of the last publish. +//! the state as of the last publish. The exceptions are counters that live in +//! shared atomics, which are read at request time: the `MetricsRegistry` +//! families, and the transport counters `show_transports` reports, whose rows +//! hold the transports' shared stats rather than a copy of them. //! //! [`snapshot_dispatch`] is the seam: it serves the commands in its match arms //! directly from the handle and returns `None` for everything else, so the diff --git a/src/control/snapshot.rs b/src/control/snapshot.rs index c7263b07..d93a6fb0 100644 --- a/src/control/snapshot.rs +++ b/src/control/snapshot.rs @@ -727,10 +727,18 @@ pub(crate) struct ConnectionRow { pub expected_peer: Option, } -/// One transport instance in `show_transports`. The `stats` and -/// `tor_monitoring` fields are stored as already-projected `serde_json::Value` -/// (data, produced by the transport handle), not as rendered `Response` -/// envelopes. +/// One transport instance in `show_transports`. The `tor_monitoring` field is +/// stored as an already-projected `serde_json::Value` (data, produced by the +/// transport handle), not as a rendered `Response` envelope. +/// +/// `stats` is the exception to the snapshot being a point-in-time copy: it +/// holds the transport's shared counters, which the query reads at request +/// time. They are atomics the transport updates from its own tasks, so they +/// stay current when the tick that publishes this row is late or held, which +/// is when an operator most needs them. The rest of the row is copied at +/// publish time like every other row. Equality compares the counters by +/// identity, so a row whose other fields are unchanged is reused across +/// publishes however much traffic the transport carried. #[derive(Clone, PartialEq)] pub(crate) struct TransportRow { pub transport_id: u32, @@ -742,7 +750,7 @@ pub(crate) struct TransportRow { pub tor_mode: Option, pub onion_address: Option, pub tor_monitoring: Option, - pub stats: serde_json::Value, + pub stats: crate::transport::LiveStats, } /// MMP trend labels for a peer's link-layer block in `show_mmp` (each present diff --git a/src/node/dataplane/connected_udp.rs b/src/node/dataplane/connected_udp.rs index 090dd315..7cf88f14 100644 --- a/src/node/dataplane/connected_udp.rs +++ b/src/node/dataplane/connected_udp.rs @@ -119,7 +119,7 @@ impl Node { // the UDP transport's DNS cache. This may await on a DNS // lookup the very first time we see a hostname; subsequent // calls hit the cache. - let (peer_socket_addr, local_addr, recv_buf, send_buf, packet_tx) = { + let (peer_socket_addr, local_addr, recv_buf, send_buf, packet_tx, stats) = { let Some(transport) = self.transports.get(&transport_id) else { return Ok(()); }; @@ -137,7 +137,7 @@ impl Node { let recv_buf = udp.recv_buf_size(); let send_buf = udp.send_buf_size(); let tx = udp.clone_packet_tx(); - (peer_sa, local, recv_buf, send_buf, tx) + (peer_sa, local, recv_buf, send_buf, tx, udp.stats().clone()) }; // Open the connected socket on the kernel side, then adopt the @@ -155,13 +155,15 @@ impl Node { local_addr, )); - // Spawn the drain thread. It feeds `packet_tx` exactly like - // the wildcard listen socket — rx_loop dispatches identically. + // Spawn the drain thread. It feeds `packet_tx` and counts into + // the transport's stats exactly like the wildcard listen socket, + // so rx_loop dispatches identically. let drain = crate::transport::udp::PeerRecvDrain::spawn( socket.clone(), transport_id, peer_socket_addr, packet_tx, + stats, ) .map_err(|e| format!("PeerRecvDrain::spawn: {e}"))?; diff --git a/src/node/dataplane/peer_actions.rs b/src/node/dataplane/peer_actions.rs index ca065a1f..7f1acae3 100644 --- a/src/node/dataplane/peer_actions.rs +++ b/src/node/dataplane/peer_actions.rs @@ -3,8 +3,9 @@ //! The per-peer FSM in [`crate::peer::machine`] is a sans-IO reducer: it decides //! *what* must happen and returns a `Vec`; this module is the *doing* //! half — the thin driver that maps each action onto the exact shell call it -//! stands for (`build_msg2` + `transport.send`, `promote_connection`, -//! `remove_active_peer`, `index_allocator.free`, `note_link_dead`, …). +//! stands for (`build_msg2` + `send_existing`, `send_stored_msg1`, +//! `promote_connection`, `remove_active_peer`, `index_allocator.free`, +//! `note_link_dead`, …). //! //! ## Progressive cutover //! @@ -179,11 +180,16 @@ impl Node { // `if let Some(transport)` guard); a send *error* runs the // pre-refactor msg2-send-failure cleanup (`handle_msg1` // L494-503) and ABORTS the remaining queue so the queued - // `PromoteToActive` never runs. + // `PromoteToActive` never runs. The send never dials: + // if the msg1's connection has closed, a dial to its + // address (for an inbound connection, the initiator's + // ephemeral port) would hold the rx loop for up to the + // connect timeout. let send_err = match self.transports.get(&ambient.transport_id) { - Some(transport) => { - transport.send(&ambient.remote_addr, &frame).await.err() - } + Some(transport) => transport + .send_existing(&ambient.remote_addr, &frame) + .await + .err(), None => None, }; if let Some(e) = send_err { diff --git a/src/node/encrypt_worker.rs b/src/node/encrypt_worker.rs index d8cd4da7..dd7a16ba 100644 --- a/src/node/encrypt_worker.rs +++ b/src/node/encrypt_worker.rs @@ -52,6 +52,7 @@ use crate::proto::fmp::wire::ESTABLISHED_HEADER_SIZE; use crate::proto::fsp::wire::FSP_HEADER_SIZE; +use crate::transport::udp::UdpStats; use crate::transport::udp::io::AsyncUdpSocket; #[cfg(not(target_os = "macos"))] use crossbeam_channel::{Receiver, SendError, Sender, TrySendError, bounded}; @@ -137,6 +138,12 @@ pub(crate) struct FmpSendJob { /// strong ref remains. #[cfg(any(target_os = "linux", target_os = "macos"))] pub connected_socket: Option>, + /// The sending UDP transport's counters. The worker's sends bypass + /// `UdpTransport::send_async`, so the worker counts each datagram it + /// hands the kernel, and each it gives up on, here; the transport's + /// send counters then cover every datagram it sends, on the wildcard + /// socket and on per-peer connected sockets alike. + pub stats: Arc, /// Bulk endpoint data may be dropped when the kernel reports UDP /// send-queue exhaustion. Control/rekey frames keep retrying so /// congestion cannot strand the session. @@ -621,6 +628,7 @@ impl MacSequencedSendFlows { job.socket.clone(), job.connected_socket.clone(), job.dest_addr, + job.stats.clone(), now_ms, ); flows.insert(key, Arc::clone(&flow)); @@ -744,6 +752,9 @@ struct MacSequencedSendFlow { socket: AsyncUdpSocket, connected_socket: Option>, dest_addr: SocketAddr, + /// The sending transport's counters, which this flow's sender thread + /// counts each datagram into. + stats: Arc, next_seq: portable_atomic::AtomicU64, last_used_ms: portable_atomic::AtomicU64, state: Mutex, @@ -852,6 +863,7 @@ impl MacSequencedSendFlow { socket: AsyncUdpSocket, connected_socket: Option>, dest_addr: SocketAddr, + stats: Arc, now_ms: u64, ) -> Arc { let flow = Arc::new(Self { @@ -859,6 +871,7 @@ impl MacSequencedSendFlow { socket, connected_socket, dest_addr, + stats, next_seq: portable_atomic::AtomicU64::new(0), last_used_ms: portable_atomic::AtomicU64::new(now_ms), state: Mutex::new(MacSendFlowState::default()), @@ -1008,6 +1021,7 @@ impl MacSequencedSendFlow { &packet, &mut backpressure, drop_on_backpressure, + &self.stats, ) { debug!( socket_fd = self.key.socket_fd, @@ -1148,6 +1162,7 @@ fn flush_batch_sync( #[cfg(any(target_os = "linux", target_os = "macos"))] connected_socket: Option>, dest_addr: SocketAddr, + stats: Arc, wire_packets: Vec>, drop_on_backpressure: bool, } @@ -1171,6 +1186,7 @@ fn flush_batch_sync( dest_addr, #[cfg(any(target_os = "linux", target_os = "macos"))] connected_socket, + stats, drop_on_backpressure, queued_at, } = job; @@ -1264,7 +1280,7 @@ fn flush_batch_sync( if g.dest_addr != dest_addr { return false; } - if g.socket.as_raw_fd() != socket_fd { + if g.socket.as_raw_fd() != socket_fd || !Arc::ptr_eq(&g.stats, &stats) { return false; } #[cfg(any(target_os = "linux", target_os = "macos"))] @@ -1284,6 +1300,7 @@ fn flush_batch_sync( #[cfg(any(target_os = "linux", target_os = "macos"))] connected_socket, dest_addr, + stats, wire_packets: vec![wire_buf], drop_on_backpressure, }); @@ -1294,7 +1311,7 @@ fn flush_batch_sync( // Windows: encrypt worker pool isn't spawned (see // lifecycle.rs); this function is unreachable. Drop // values explicitly so the compiler sees them as used. - let _ = (socket, dest_addr, wire_buf); + let _ = (socket, dest_addr, stats, wire_buf); } } @@ -1328,13 +1345,27 @@ fn flush_batch_sync( // full so this is the cold path. let _t2 = crate::perf_profile::Timer::start(crate::perf_profile::Stage::UdpSend); + // Every datagram is counted once in its transport's stats: as sent + // when the kernel takes it, as a send error when it is given up on. + // A hard error ends the flush, so the groups after the failing one + // are never tried; `abandon` counts their datagrams as send errors. + #[cfg(unix)] + let mut groups = groups.into_iter(); + #[cfg(unix)] + let abandon = |rest: std::vec::IntoIter| { + for group in rest { + group.stats.record_unsent(group.wire_packets.len() as u64); + } + }; + #[cfg(target_os = "linux")] - for group in groups { + while let Some(group) = groups.next() { let mut backpressure = SendBackpressurePacer::default(); let EncryptedGroup { socket, connected_socket, dest_addr, + stats, wire_packets, drop_on_backpressure: _, } = group; @@ -1351,6 +1382,7 @@ fn flush_batch_sync( match send_batch_gso(fd, &wire_packets, dest_addr, connected) { Ok(()) => { record_udp_send_path(connected, wire_packets.len() as u64); + stats.record_sends(wire_packets.len() as u64, wire_bytes(&wire_packets)); continue; } Err(err) @@ -1370,6 +1402,8 @@ fn flush_batch_sync( // sendmmsg retry loop. No GSO_DISABLED toggle. } Err(err) => { + stats.record_unsent(wire_packets.len() as u64); + abandon(groups); return Err(format!("sendmsg+UDP_GSO failed: {err}").into()); } } @@ -1384,19 +1418,23 @@ fn flush_batch_sync( continue; } Err(err) => { + stats.record_unsent((wire_packets.len() - sent) as u64); + abandon(groups); return Err(format!("sendmmsg(2) failed: {err}").into()); } }; if n == 0 { + stats.record_unsent((wire_packets.len() - sent) as u64); break; } + stats.record_sends(n as u64, wire_bytes(&wire_packets[sent..sent + n])); sent += n; backpressure.record_success(); record_udp_send_path(connected, n as u64); } } #[cfg(all(unix, not(target_os = "linux")))] - for group in groups { + while let Some(group) = groups.next() { let mut backpressure = SendBackpressurePacer::default(); #[cfg(target_os = "macos")] let (fd, connected) = match group.connected_socket.as_ref() { @@ -1405,7 +1443,7 @@ fn flush_batch_sync( }; #[cfg(not(target_os = "macos"))] let (fd, connected) = (group.socket.as_raw_fd(), false); - for data in &group.wire_packets { + for (i, data) in group.wire_packets.iter().enumerate() { if let Err(err) = send_one_with_backpressure( fd, connected, @@ -1413,10 +1451,14 @@ fn flush_batch_sync( data, &mut backpressure, group.drop_on_backpressure, + &group.stats, ) { if group.drop_on_backpressure && is_send_backpressure(&err) { continue; } + let rest = group.wire_packets.len() - i - 1; + group.stats.record_unsent(rest as u64); + abandon(groups); return Err(format!("sendto failed: {err}").into()); } } @@ -1445,6 +1487,13 @@ fn record_udp_send_path(connected: bool, count: u64) { crate::perf_profile::record_event_count(event, count); } +/// Total bytes in `packets`: the UDP payload bytes one batched send +/// hands the kernel when it takes every packet in the slice. +#[cfg(target_os = "linux")] +fn wire_bytes(packets: &[Vec]) -> u64 { + packets.iter().map(|p| p.len() as u64).sum() +} + fn is_send_backpressure(err: &std::io::Error) -> bool { err.kind() == std::io::ErrorKind::WouldBlock || err.raw_os_error().is_some_and(raw_send_backpressure_code) @@ -1692,6 +1741,12 @@ impl MacSendRatePacer { #[cfg(target_os = "linux")] static GSO_DISABLED: std::sync::atomic::AtomicBool = std::sync::atomic::AtomicBool::new(false); +/// The most packets one UDP GSO send carries, the kernel's segment limit +/// on older kernels. `send_batch_gso` reports a whole group as sent, so a +/// larger group must not reach it. +#[cfg(target_os = "linux")] +const GSO_SEGMENTS: usize = 64; + /// Size-only GSO eligibility check. Callers MUST ensure all packets /// share one destination + send target — `flush_batch_sync` does this /// by grouping. A batch is GSO-eligible iff every packet is the same @@ -1705,6 +1760,10 @@ fn gso_eligible_sizes(packets: &[Vec]) -> bool { // saving) and just add cmsg overhead. return false; } + if packets.len() > GSO_SEGMENTS { + // More than one GSO send can carry; sendmmsg's loop sends them all. + return false; + } let seg = packets[0].len(); if seg == 0 { return false; @@ -1734,8 +1793,8 @@ fn send_batch_gso( connected: bool, ) -> std::io::Result<()> { debug_assert!(!packets.is_empty()); - const MAX_BATCH: usize = 64; - let n = packets.len().min(MAX_BATCH); + debug_assert!(packets.len() <= GSO_SEGMENTS); + let n = packets.len().min(GSO_SEGMENTS); if n == 0 { return Ok(()); } @@ -1744,7 +1803,7 @@ fn send_batch_gso( let sa: socket2::SockAddr = dest.into(); // Stack-allocated arrays sized for the worst case in this batch. - let mut iovs: [libc::iovec; MAX_BATCH] = unsafe { std::mem::zeroed() }; + let mut iovs: [libc::iovec; GSO_SEGMENTS] = unsafe { std::mem::zeroed() }; for (i, data) in packets[..n].iter().enumerate() { iovs[i].iov_base = data.as_ptr() as *mut libc::c_void; iovs[i].iov_len = data.len(); @@ -1952,6 +2011,7 @@ mod unix_tests { dest_addr: recv_addr, #[cfg(any(target_os = "linux", target_os = "macos"))] connected_socket: None, + stats: Arc::new(UdpStats::new()), drop_on_backpressure: true, queued_at: None, }]; @@ -2085,6 +2145,7 @@ mod unix_tests { dest_addr: recv_addr, #[cfg(any(target_os = "linux", target_os = "macos"))] connected_socket: None, + stats: Arc::new(UdpStats::new()), drop_on_backpressure: true, queued_at: None, }]; @@ -2153,6 +2214,254 @@ mod unix_tests { assert_eq!(recovered_fsp_plaintext, fsp_plaintext); }); } + + /// A job carrying `plaintext_len` bytes of plaintext for `dest`, sent + /// on `socket` and counted in `stats`. Its wire packet is + /// `ESTABLISHED_HEADER_SIZE + plaintext_len + TAG_SIZE` bytes. + fn counted_job( + socket: &AsyncUdpSocket, + dest: SocketAddr, + plaintext_len: usize, + counter: u64, + stats: &Arc, + ) -> FmpSendJob { + let mut wire_buf = + Vec::with_capacity(ESTABLISHED_HEADER_SIZE + plaintext_len + crate::noise::TAG_SIZE); + wire_buf.extend_from_slice(&[0xA5; ESTABLISHED_HEADER_SIZE]); + wire_buf.resize(ESTABLISHED_HEADER_SIZE + plaintext_len, 0); + FmpSendJob { + cipher: test_cipher(3), + counter, + wire_buf, + fsp_seal: None, + socket: socket.clone(), + dest_addr: dest, + #[cfg(any(target_os = "linux", target_os = "macos"))] + connected_socket: None, + stats: stats.clone(), + drop_on_backpressure: false, + queued_at: None, + } + } + + /// The wire length of a `counted_job` carrying `plaintext_len` bytes. + fn wire_len(plaintext_len: usize) -> u64 { + (ESTABLISHED_HEADER_SIZE + plaintext_len + crate::noise::TAG_SIZE) as u64 + } + + /// Receive datagrams on `sock` until it goes quiet, returning how many + /// arrived. + fn count_received(sock: &UdpSocket) -> u64 { + sock.set_read_timeout(Some(std::time::Duration::from_millis(200))) + .expect("set_read_timeout"); + let mut buf = [0u8; 2048]; + let mut n = 0; + while sock.recv_from(&mut buf).is_ok() { + n += 1; + } + n + } + + /// A nonblocking loopback send socket registered with `rt`'s reactor. + fn open_async(rt: &tokio::runtime::Runtime) -> AsyncUdpSocket { + let _enter = rt.enter(); + UdpRawSocket::open("127.0.0.1:0".parse().unwrap(), 1 << 20, 1 << 20) + .expect("open send socket") + .into_async() + .expect("into_async") + } + + /// The worker's sends bypass `UdpTransport::send_async`, so the worker + /// must count them itself: each datagram it hands the kernel counts + /// once, in the stats of the transport whose job it was. The batch + /// mixes a same-size run (the UDP GSO group on Linux), a lone packet + /// to a second destination (plain `sendmmsg`), and a job from a second + /// transport, whose datagram must land in that transport's stats only. + #[test] + fn each_datagram_a_flush_sends_counts_once_in_its_own_transports_stats() { + let rt = tokio::runtime::Builder::new_current_thread() + .enable_io() + .build() + .expect("tokio rt"); + let recv_a = UdpSocket::bind("127.0.0.1:0").expect("bind recv_a"); + let recv_b = UdpSocket::bind("127.0.0.1:0").expect("bind recv_b"); + let addr_a = recv_a.local_addr().unwrap(); + let addr_b = recv_b.local_addr().unwrap(); + let first = open_async(&rt); + let second = open_async(&rt); + let stats = Arc::new(UdpStats::new()); + let other = Arc::new(UdpStats::new()); + + const RUN: u64 = 6; + const RUN_LEN: usize = 100; + const LONE_LEN: usize = 40; + const OTHER_LEN: usize = 60; + let mut batch: Vec = (0..RUN) + .map(|i| counted_job(&first, addr_a, RUN_LEN, i, &stats)) + .collect(); + batch.push(counted_job(&first, addr_b, LONE_LEN, RUN, &stats)); + batch.push(counted_job(&second, addr_b, OTHER_LEN, RUN + 1, &other)); + flush_direct_batch_sync(&mut batch).expect("flush ok"); + + assert_eq!(count_received(&recv_a), RUN); + assert_eq!(count_received(&recv_b), 2); + let counted = stats.snapshot(); + assert_eq!( + counted.packets_sent, + RUN + 1, + "each datagram the worker sent must count once" + ); + assert_eq!( + counted.bytes_sent, + RUN * wire_len(RUN_LEN) + wire_len(LONE_LEN) + ); + assert_eq!(counted.send_errors, 0); + let counted = other.snapshot(); + assert_eq!( + counted.packets_sent, 1, + "a datagram must count in the stats of the transport whose job it was" + ); + assert_eq!(counted.bytes_sent, wire_len(OTHER_LEN)); + } + + /// Datagrams sent on a per-peer connected socket count in the stats + /// of the transport the job came from, as wildcard sends do. + #[cfg(any(target_os = "linux", target_os = "macos"))] + #[test] + fn datagrams_sent_on_a_connected_socket_count_once_in_the_transports_stats() { + let rt = tokio::runtime::Builder::new_current_thread() + .enable_io() + .build() + .expect("tokio rt"); + let recv = UdpSocket::bind("127.0.0.1:0").expect("bind recv"); + let peer = recv.local_addr().unwrap(); + let local: SocketAddr = "127.0.0.1:0".parse().unwrap(); + let owned = crate::transport::udp::open_connected_fd(local, peer, 1 << 16, 1 << 16) + .expect("open a connected UDP socket"); + let connected = Arc::new(crate::transport::udp::ConnectedPeerSocket::from_fd( + owned, peer, local, + )); + let wildcard = open_async(&rt); + let stats = Arc::new(UdpStats::new()); + + const N: u64 = 4; + const LEN: usize = 80; + let mut batch: Vec = (0..N) + .map(|i| { + let mut job = counted_job(&wildcard, peer, LEN, i, &stats); + job.connected_socket = Some(connected.clone()); + job + }) + .collect(); + flush_direct_batch_sync(&mut batch).expect("flush ok"); + + assert_eq!(count_received(&recv), N); + let counted = stats.snapshot(); + assert_eq!(counted.packets_sent, N); + assert_eq!(counted.bytes_sent, N * wire_len(LEN)); + assert_eq!(counted.send_errors, 0); + } + + /// A hard send error ends the flush. The failing datagram and every + /// datagram the flush then never tries count as send errors, none as + /// sent. The failing destination is an IPv6 address on an IPv4 + /// socket, which the kernel refuses outright; it is a single packet so + /// the Linux GSO path, whose refusal would switch GSO off for the + /// whole process, is not taken. + #[test] + fn datagrams_a_flush_abandons_on_a_send_error_count_as_send_errors() { + let rt = tokio::runtime::Builder::new_current_thread() + .enable_io() + .build() + .expect("tokio rt"); + let recv = UdpSocket::bind("127.0.0.1:0").expect("bind recv"); + let good = recv.local_addr().unwrap(); + let bad: SocketAddr = "[::1]:9".parse().unwrap(); + let socket = open_async(&rt); + let stats = Arc::new(UdpStats::new()); + + let mut batch = vec![ + counted_job(&socket, bad, 40, 0, &stats), + counted_job(&socket, good, 50, 1, &stats), + counted_job(&socket, good, 70, 2, &stats), + ]; + assert!( + flush_direct_batch_sync(&mut batch).is_err(), + "precondition: the kernel refuses the IPv6 destination" + ); + + assert_eq!(count_received(&recv), 0); + let counted = stats.snapshot(); + assert_eq!(counted.packets_sent, 0); + assert_eq!(counted.bytes_sent, 0); + assert_eq!( + counted.send_errors, 3, + "the refused datagram and the two never tried must each count once" + ); + } + + /// A hard error on the Linux UDP GSO path ends the flush as one on + /// `sendmmsg` does: every datagram of the failing group and of the + /// groups after it counts as a send error, none as sent. The error is + /// the ECONNREFUSED a connected socket reports after an ICMP port + /// unreachable; unlike EINVAL, it does not switch GSO off for the + /// whole process. On a kernel without UDP GSO the group takes + /// `sendmmsg` and the counts must hold the same. + #[cfg(target_os = "linux")] + #[test] + fn datagrams_a_gso_send_error_abandons_count_as_send_errors() { + let rt = tokio::runtime::Builder::new_current_thread() + .enable_io() + .build() + .expect("tokio rt"); + let closed = UdpSocket::bind("127.0.0.1:0").expect("bind closed"); + let peer = closed.local_addr().unwrap(); + drop(closed); + let recv = UdpSocket::bind("127.0.0.1:0").expect("bind recv"); + let good = recv.local_addr().unwrap(); + let local: SocketAddr = "127.0.0.1:0".parse().unwrap(); + let owned = crate::transport::udp::open_connected_fd(local, peer, 1 << 16, 1 << 16) + .expect("open a connected UDP socket"); + let connected = Arc::new(crate::transport::udp::ConnectedPeerSocket::from_fd( + owned, peer, local, + )); + let wildcard = open_async(&rt); + let to_peer = |len: usize, counter: u64, stats: &Arc| { + let mut job = counted_job(&wildcard, peer, len, counter, stats); + job.connected_socket = Some(connected.clone()); + job + }; + + // One datagram to the closed port draws the ICMP port unreachable + // that the socket's next send reports as ECONNREFUSED. + let mut prime = vec![to_peer(40, 0, &Arc::new(UdpStats::new()))]; + flush_direct_batch_sync(&mut prime).expect("priming send ok"); + std::thread::sleep(std::time::Duration::from_millis(50)); + + const RUN: u64 = 4; + const LEN: usize = 100; + let stats = Arc::new(UdpStats::new()); + let mut batch: Vec = (1..=RUN).map(|i| to_peer(LEN, i, &stats)).collect(); + batch.push(counted_job(&wildcard, good, 40, RUN + 1, &stats)); + let err = flush_direct_batch_sync(&mut batch) + .expect_err("precondition: the connected socket reports the refused port"); + if !GSO_DISABLED.load(std::sync::atomic::Ordering::Relaxed) { + assert!( + err.to_string().contains("UDP_GSO"), + "precondition: the same-size group must fail on the GSO path, got: {err}" + ); + } + + assert_eq!(count_received(&recv), 0); + let counted = stats.snapshot(); + assert_eq!(counted.packets_sent, 0); + assert_eq!(counted.bytes_sent, 0); + assert_eq!( + counted.send_errors, + RUN + 1, + "the failing group's datagrams and the one never tried must each count once" + ); + } } /// Standalone tests for the GSO-eligibility predicate. The full @@ -2186,6 +2495,14 @@ mod tests { assert!(gso_eligible_sizes(&batch)); } + #[test] + fn gso_eligible_rejects_a_group_larger_than_one_gso_send_carries() { + let at_cap: Vec<_> = (0..GSO_SEGMENTS).map(|_| pkt(1500)).collect(); + assert!(gso_eligible_sizes(&at_cap)); + let over: Vec<_> = (0..=GSO_SEGMENTS).map(|_| pkt(1500)).collect(); + assert!(!gso_eligible_sizes(&over)); + } + #[test] fn gso_eligible_rejects_mixed_sizes() { let mut batch: Vec<_> = (0..18).map(|_| pkt(1500)).collect(); @@ -2391,6 +2708,7 @@ mod tests { dest_addr: dest, #[cfg(any(target_os = "linux", target_os = "macos"))] connected_socket: None, + stats: Arc::new(UdpStats::new()), drop_on_backpressure: true, queued_at: None, } @@ -2458,6 +2776,9 @@ fn send_connected_raw(fd: std::os::unix::io::RawFd, data: &[u8]) -> std::io::Res } } +/// Send one datagram, retrying while the kernel reports backpressure, and +/// count it once in `stats`: as sent, or as a send error when it is +/// dropped under backpressure or the send fails. #[cfg(all(unix, not(target_os = "linux")))] fn send_one_with_backpressure( fd: std::os::unix::io::RawFd, @@ -2466,6 +2787,7 @@ fn send_one_with_backpressure( data: &[u8], backpressure: &mut SendBackpressurePacer, drop_on_backpressure: bool, + stats: &UdpStats, ) -> std::io::Result<()> { loop { let result = if connected { @@ -2474,18 +2796,23 @@ fn send_one_with_backpressure( send_one_raw(fd, data, dest) }; match result { - Ok(_) => { + Ok(bytes) => { backpressure.record_success(); record_udp_send_path(connected, 1); + stats.record_send(bytes); return Ok(()); } Err(err) if is_send_backpressure(&err) => { if backpressure.pause(&err) && drop_on_backpressure { record_udp_send_backpressure_drop(&err); + stats.record_send_error(); return Err(err); } } - Err(err) => return Err(err), + Err(err) => { + stats.record_send_error(); + return Err(err); + } } } } @@ -2693,6 +3020,7 @@ mod mac_ordered_tests { socket: socket.clone(), dest_addr: dest, connected_socket: None, + stats: Arc::new(UdpStats::new()), drop_on_backpressure: false, queued_at: None, } diff --git a/src/node/handlers/handshake.rs b/src/node/handlers/handshake.rs index 9e32fdd3..a30d8a00 100644 --- a/src/node/handlers/handshake.rs +++ b/src/node/handlers/handshake.rs @@ -17,7 +17,7 @@ use crate::proto::fmp::{ EstablishSnapshot, EstablishView, InboundDecision, InboundReject, Msg1Digest, OutboundSnapshot, PromotionResult, RekeyAnswer, WireOutcome, cross_connection_winner, }; -use crate::transport::{Link, LinkDirection, LinkId, ReceivedPacket}; +use crate::transport::{Link, LinkDirection, LinkId, ReceivedPacket, TransportError, TransportId}; use crate::utils::index::SessionIndex; use std::time::{Duration, Instant}; use tracing::{debug, info, warn}; @@ -313,8 +313,8 @@ impl Node { .is_none_or(|t| t.accept_connections()) } - /// The transport and address of `peer`'s established link, where a rekey - /// msg2 is sent whatever address its msg1 arrived from. + /// The transport and address of `peer`'s established link, where a reply + /// to the peer's msg1 goes first, whatever address the msg1 arrived from. fn established_link( &self, peer: &NodeAddr, @@ -326,6 +326,64 @@ impl Node { Some((p.transport_id()?, p.current_addr()?.clone())) } + /// Send `reply`, an answer to `packet`'s msg1 from `peer`, on the peer's + /// established link, or on the connection the msg1 arrived on when the + /// established link's connection has gone. Returns the transport the + /// reply went out on. + /// + /// Neither send dials. The arrival connection is used only on a + /// connection-oriented transport: the remote opened it, so a reply on it + /// reaches only the remote. That is how a peer that redialed after its + /// old connection closed has its msg1 answered before the old link is + /// reaped. A connectionless source address is whatever the sender wrote, + /// so a msg1 that came that way is answered on the established link only. + /// + /// The arrival connection must also be on the established link's + /// transport. Session indices are looked up and retired by transport, and + /// the retirement paths use the transport the peer's link is on, so an + /// answer on another transport would leave the new index registered + /// where the peer's frames are not looked up, and never removed. + /// + /// The fallback needs the established connection to be gone from the + /// pool. A half-open one, whose path broke without a FIN or reset + /// reaching this node, still accepts writes, so the reply is lost there + /// until the link-dead reaper removes the peer. + async fn answer_msg1( + &self, + peer: &NodeAddr, + packet: &ReceivedPacket, + reply: &[u8], + ) -> Result { + let (tid, addr) = self + .established_link(peer) + .ok_or_else(|| "the peer has no established link".to_string())?; + let transport = self + .transports + .get(&tid) + .ok_or_else(|| "no transport for the peer's link".to_string())?; + match transport.send_existing(&addr, reply).await { + Ok(_) => return Ok(tid), + Err(TransportError::NotConnected) => {} + Err(e) => return Err(e.to_string()), + } + if packet.transport_id != tid + || packet.remote_addr == addr + || !transport.transport_type().connection_oriented + { + return Err(TransportError::NotConnected.to_string()); + } + transport + .send_existing(&packet.remote_addr, reply) + .await + .map_err(|e| format!("established link not connected; msg1's connection: {e}"))?; + debug!( + peer = %self.peer_display_name(peer), + remote_addr = %packet.remote_addr, + "Established link not connected, answered on the msg1's connection" + ); + Ok(tid) + } + /// Handle handshake message 1 (phase 0x1). /// /// This creates a new inbound connection. Rate limiting is applied @@ -435,7 +493,7 @@ impl Node { let msg2_bytes = self.find_stored_msg2(existing_link_id); if let Some(msg2) = msg2_bytes { if let Some(transport) = self.transports.get(&packet.transport_id) { - match transport.send(&packet.remote_addr, &msg2).await { + match transport.send_existing(&packet.remote_addr, &msg2).await { Ok(_) => debug!( remote_addr = %packet.remote_addr, "Resent msg2 for duplicate msg1" @@ -651,13 +709,13 @@ impl Node { // the classification touched no state. It goes on the peer's // established link, as a rekey msg2 does: a genuine duplicate // comes from the address the peering was just formed with, - // while a copy can come from anywhere. + // while a copy can come from anywhere. On a connection-oriented + // transport whose established connection has gone, it goes on + // the msg1's own connection on that transport instead + // (`answer_msg1`). debug_assert!(actions.is_empty()); - if let Some(msg2) = msg2.as_deref() - && let Some((tid, addr)) = self.established_link(&peer_node_addr) - && let Some(transport) = self.transports.get(&tid) - { - match transport.send(&addr, msg2).await { + if let Some(msg2) = msg2.as_deref() { + match self.answer_msg1(&peer_node_addr, &packet, msg2).await { Ok(_) => debug!( peer = %self.peer_display_name(&peer_node_addr), "Resent msg2 for duplicate msg1 (same epoch)" @@ -672,28 +730,19 @@ impl Node { } InboundDecision::ResendRekeyMsg2 { peer, msg2 } => { // A resend of the msg1 that armed the pending we hold: our - // msg2 was lost, so give the same answer again, on the peer's - // established link as the first answer went. + // msg2 was lost, so give the same answer again, routed as the + // first answer was (`answer_msg1`). debug_assert!(actions.is_empty()); - if let Some((tid, addr)) = self.established_link(&peer) - && let Some(transport) = self.transports.get(&tid) - { - match transport.send(&addr, &msg2).await { - Ok(_) => debug!( - peer = %self.peer_display_name(&peer), - "Resent rekey msg2 for a resent msg1" - ), - Err(e) => debug!( - peer = %self.peer_display_name(&peer), - error = %e, - "Failed to resend rekey msg2" - ), - } - } else { - debug!( + match self.answer_msg1(&peer, &packet, &msg2).await { + Ok(_) => debug!( peer = %self.peer_display_name(&peer), - "No established link to resend rekey msg2 on" - ); + "Resent rekey msg2 for a resent msg1" + ), + Err(e) => debug!( + peer = %self.peer_display_name(&peer), + error = %e, + "Failed to resend rekey msg2" + ), } } InboundDecision::RekeyRespond { @@ -751,19 +800,14 @@ impl Node { // of a msg1 authenticates as the peer from any address, so // answering its source would reflect to an address the // sender chose. A peer whose address changed is answered at - // the old one until a frame from the new address moves it. + // the old one until a frame from the new address moves it, + // except that on a connection-oriented transport whose + // established connection has gone, the msg1's own connection + // on that transport is used (`answer_msg1`): a peer that + // redialed sends only msg1s on its new connection, so nothing + // else would move it. let wire_msg2 = build_msg2(our_new_index, wire.their_index, &wire.msg2_payload); - let sent = match self.established_link(&peer) { - Some((tid, addr)) => match self.transports.get(&tid) { - Some(transport) => transport - .send(&addr, &wire_msg2) - .await - .map(|_| tid) - .map_err(|e| e.to_string()), - None => Err("no transport for the peer's link".to_string()), - }, - None => Err("the peer has no established link".to_string()), - }; + let sent = self.answer_msg1(&peer, &packet, &wire_msg2).await; let link_transport = match sent { Ok(tid) => tid, Err(e) => { diff --git a/src/node/handlers/rekey.rs b/src/node/handlers/rekey.rs index f641f772..c4c8a1c5 100644 --- a/src/node/handlers/rekey.rs +++ b/src/node/handlers/rekey.rs @@ -455,9 +455,15 @@ impl Node { let wire_msg1 = build_msg1(our_index, &noise_msg1); - // Send msg1 on the existing link (same transport + address) + // Send msg1 on the existing link (same transport + address). This + // runs on the tick, so it never dials: with the connection gone it + // fails at once, the index is freed, and the next tick's trigger + // tries again, by then over any connection the failed send started. if let Some(transport) = self.transports.get(&transport_id) { - match transport.send(&remote_addr, &wire_msg1).await { + match self + .send_nowait(transport, link_id, &remote_addr, &wire_msg1) + .await + { Ok(_) => { debug!( peer = %self.peer_display_name(node_addr), @@ -556,16 +562,21 @@ impl Node { bytes, next_resend_at_ms, } => { - let (transport_id, remote_addr) = match self.peers.get(&node_addr) { + let (link_id, transport_id, remote_addr) = match self.peers.get(&node_addr) { Some(p) => match (p.transport_id(), p.current_addr()) { - (Some(tid), Some(addr)) => (tid, addr.clone()), + (Some(tid), Some(addr)) => (p.link_id(), tid, addr.clone()), _ => continue, }, None => continue, }; + // A failed send records no resend, so the msg1 stays due + // and is retried next tick, over any connection the + // failed send started. let sent = if let Some(transport) = self.transports.get(&transport_id) { - transport.send(&remote_addr, &bytes).await.is_ok() + self.send_nowait(transport, link_id, &remote_addr, &bytes) + .await + .is_ok() } else { false }; diff --git a/src/node/handlers/session.rs b/src/node/handlers/session.rs index 4d4c1f7b..d3b3f770 100644 --- a/src/node/handlers/session.rs +++ b/src/node/handlers/session.rs @@ -2749,6 +2749,7 @@ impl Node { let Some(socket) = udp.async_socket() else { return Ok(false); }; + let stats = udp.stats().clone(); // FSP cipher + counter — separate session from next-hop FMP session. let (fsp_counter, fsp_cipher) = { @@ -2889,6 +2890,7 @@ impl Node { dest_addr: socket_addr, #[cfg(any(target_os = "linux", target_os = "macos"))] connected_socket, + stats, // Bulk endpoint data: drop on UDP backpressure so the // worker queue keeps moving instead of stranding under // sustained congestion. diff --git a/src/node/handlers/timeout.rs b/src/node/handlers/timeout.rs index aa833b2f..444ff92f 100644 --- a/src/node/handlers/timeout.rs +++ b/src/node/handlers/timeout.rs @@ -359,7 +359,10 @@ impl Node { }; let sent = if let Some(transport) = self.transports.get(&transport_id) { - match transport.send(&remote_addr, &bytes).await { + match self + .send_nowait(transport, link, &remote_addr, &bytes) + .await + { Ok(_) => true, Err(e) => { debug!( diff --git a/src/node/lifecycle/mod.rs b/src/node/lifecycle/mod.rs index cca08fd2..7efc5200 100644 --- a/src/node/lifecycle/mod.rs +++ b/src/node/lifecycle/mod.rs @@ -774,9 +774,15 @@ impl Node { .filter(|machine| machine.leg().is_some()) .and_then(|machine| machine.our_index()); - // Send the wire format handshake message + // Send the wire format handshake message. It never dials: if the + // connection the dial resolved to has gone, the send fails at once + // into the failure path below, after starting a background connect + // to the dial address that the next attempt picks up. if let Some(transport) = self.transports.get(&transport_id) { - match transport.send(remote_addr, &wire_msg1).await { + match self + .send_nowait(transport, link_id, remote_addr, &wire_msg1) + .await + { Ok(bytes) => { if let Some(idx) = our_index { debug!( diff --git a/src/node/mod.rs b/src/node/mod.rs index c53d83cc..6b228ef1 100644 --- a/src/node/mod.rs +++ b/src/node/mod.rs @@ -64,7 +64,7 @@ use crate::transport::tcp::TcpTransport; use crate::transport::tor::TorTransport; use crate::transport::udp::UdpTransport; use crate::transport::{ - ConnectionState, Link, LinkId, PacketRx, PacketTx, TransportAddr, TransportError, + Link, LinkDirection, LinkId, PacketRx, PacketTx, TransportAddr, TransportError, TransportHandle, TransportId, }; use crate::upper::hosts::HostMap; @@ -2384,6 +2384,8 @@ impl Node { .collect(); // --- transports (show_transports) --- + // `stats` shares the transport's counters rather than copying them, so + // the query reads them live even if the next tick is held. let transport_rows: Vec = self .transport_ids() .map(|id| { @@ -2400,7 +2402,7 @@ impl Node { tor_monitoring: handle .tor_monitoring() .map(|m| serde_json::to_value(&m).unwrap_or_default()), - stats: handle.transport_stats(), + stats: handle.live_stats(), } }) .collect(); @@ -3639,6 +3641,7 @@ impl Node { node_addr: *node_addr, reason: "no current_addr".into(), })?; + let link_id = peer.link_id(); // Prepend 4-byte session-relative timestamp (inner header) let timestamp_ms = peer.session_elapsed_ms(); @@ -3732,6 +3735,7 @@ impl Node { dest_addr: dest_socket_addr, #[cfg(any(target_os = "linux", target_os = "macos"))] connected_socket, + stats: udp.stats().clone(), drop_on_backpressure, queued_at: None, }); @@ -3774,29 +3778,15 @@ impl Node { .get(&transport_id) .ok_or(NodeError::TransportNotFound(transport_id))?; - // Gate: don't drive connect-on-send from the tick path. If the - // transport's connection isn't ready, kick off a non-blocking - // background connect (no-op if already in flight or pooled) and - // fail this send fast. A subsequent tick will retry once the - // pool entry exists. The historical connect-on-send wedged the - // rx_loop tick body for up to `connect_timeout_ms` (5 s default) - // per unreachable peer, which under convergence-phase mesh - // pressure cascaded into multi-tick stalls and control-RPC HOL. - match transport.connection_state(&remote_addr) { - ConnectionState::Connected => {} - other => { - if matches!(other, ConnectionState::None) { - let _ = transport.connect(&remote_addr).await; - } - return Err(NodeError::SendFailed { - node_addr: *node_addr, - reason: format!("transport connection not ready: {:?}", other), - }); - } - } - - let bytes_sent = transport - .send(&remote_addr, &wire_packet) + // Never connect-on-send here: this runs on the tick and forwarding + // paths, and a dial held the rx loop for up to `connect_timeout_ms` + // (5 s default) per unreachable peer, which under convergence-phase + // mesh pressure cascaded into multi-tick stalls and control-RPC + // head-of-line blocking. With no connection the send fails fast, + // after starting a background connect if the address is one this + // node dialed; a later send uses the connection once it is up. + let bytes_sent = self + .send_nowait(transport, link_id, &remote_addr, &wire_packet) .await .map_err(|e| match e { TransportError::MtuExceeded { packet_size, mtu } => NodeError::MtuExceeded { @@ -3821,6 +3811,59 @@ impl Node { Ok(()) } + + /// Send `data` to `addr` over a connection the transport already holds, + /// without ever waiting on a dial. + /// + /// When there is no connection the send fails at once with + /// [`TransportError::NotConnected`]. If `addr` is the address this node + /// dialed for `link_id` (see [`Self::may_dial`]), a background connect + /// is started first; it returns at once, and is a no-op while one is in + /// flight. A later send takes the finished connection into the pool and + /// uses it. + /// + /// This is the send for the tick, dial and forwarding paths, which the + /// rx loop awaits. Replies to a msg1 use + /// [`TransportHandle::send_existing`] directly: their address is the + /// sender's, and nothing should be dialed there. + pub(in crate::node) async fn send_nowait( + &self, + transport: &TransportHandle, + link_id: LinkId, + addr: &TransportAddr, + data: &[u8], + ) -> Result { + let sent = transport.send_existing(addr, data).await; + if matches!(sent, Err(TransportError::NotConnected)) + && self.may_dial(link_id, transport.transport_id(), addr) + && let Err(e) = transport.connect(addr).await + { + tracing::debug!( + link_id = %link_id, + remote_addr = %addr, + error = %e, + "Background connect not started" + ); + } + sent + } + + /// Whether a send for `link_id` may start a connect to `addr` on + /// `transport_id`: only when the link is outbound and `addr` is the + /// address it was dialed at. + /// + /// Direction alone is not enough. An inbound link's address is the + /// remote's source port, where nothing listens, and an outbound link's + /// current address follows the peer's authenticated frames, so it can + /// move to such a port too. The dial address recorded on the link is + /// the one address known to have a listener. + fn may_dial(&self, link_id: LinkId, transport_id: TransportId, addr: &TransportAddr) -> bool { + self.links.get(&link_id).is_some_and(|link| { + link.direction() == LinkDirection::Outbound + && link.transport_id() == transport_id + && link.remote_addr() == addr + }) + } } /// Shell-side [`routing::RoutingView`] seam over live `Node` state — the sole diff --git a/src/node/tests/connected_udp.rs b/src/node/tests/connected_udp.rs index a713eeef..a909189a 100644 --- a/src/node/tests/connected_udp.rs +++ b/src/node/tests/connected_udp.rs @@ -14,6 +14,10 @@ //! `bool` carries no `#[must_use]`, so discarding the return here is //! silent under `-D warnings`; the assertions below are what makes the //! difference between binding it and dropping it observable. +//! +//! The tests at the end check that datagrams the node receives through a +//! connected socket's drain, and sends through the encrypt workers on +//! either kind of socket, are counted once in the UDP transport's stats. use super::*; use crate::noise::NoiseSession; @@ -129,6 +133,7 @@ fn install_connected_udp(node: &mut Node, addr: &NodeAddr, transport_id: Transpo transport_id, peer_sa, packet_tx, + std::sync::Arc::new(crate::transport::udp::UdpStats::new()), ) .expect("spawn the peer recv drain"); @@ -217,3 +222,236 @@ async fn a_frame_from_the_address_the_peer_is_already_on_keeps_the_connected_soc "a frame from the address already in use must leave the socket alone" ); } + +/// Datagrams a peer sends after its connected socket is installed reach +/// the node through that socket's drain thread, not the wildcard listen +/// socket, and must still be counted in the UDP transport's own stats: +/// `packets_recv` means datagrams received on this transport. +/// +/// The runtime thread is blocked while the count is read, so the +/// wildcard socket's receive task (a task on this runtime) cannot be the +/// one counting; only the drain thread can. +#[cfg(any(target_os = "linux", target_os = "macos"))] +#[tokio::test] +async fn datagrams_on_a_peers_connected_socket_are_counted_in_the_udp_transport_stats() { + use crate::config::UdpConfig; + use crate::transport::udp::UdpTransport; + + const SENT: u64 = 5; + let transport_id = TransportId::new(1); + let (mut node, node_addr, _, _) = promoted_peer_with_the_far_side_session(transport_id); + let (tx, mut rx) = packet_channel(64); + let udp_cfg = UdpConfig { + bind_addr: Some("127.0.0.1:0".to_string()), + ..Default::default() + }; + let mut udp = UdpTransport::new(transport_id, None, udp_cfg, tx); + udp.start_async().await.unwrap(); + let local = udp.local_addr().unwrap(); + let stats = udp.stats().clone(); + node.transports + .insert(transport_id, TransportHandle::Udp(udp)); + + let remote = std::net::UdpSocket::bind("127.0.0.1:0").unwrap(); + node.get_peer_mut(&node_addr).unwrap().set_current_addr( + transport_id, + TransportAddr::from_string(&remote.local_addr().unwrap().to_string()), + ); + node.activate_connected_udp_sessions().await; + assert!( + node.get_peer(&node_addr).unwrap().connected_udp().is_some(), + "precondition: the tick activation installed a connected socket" + ); + + for i in 0..SENT { + remote.send_to(&[i as u8; 8], local).unwrap(); + } + // Block the runtime thread: the wildcard receive task cannot run. + let deadline = std::time::Instant::now() + Duration::from_secs(2); + while stats.snapshot().packets_recv < SENT && std::time::Instant::now() < deadline { + std::thread::sleep(Duration::from_millis(10)); + } + let counted = stats.snapshot(); + assert_eq!( + counted.packets_recv, SENT, + "datagrams read by the connected socket's drain were not counted" + ); + assert_eq!(counted.bytes_recv, SENT * 8); + + for _ in 0..SENT { + let packet = tokio::time::timeout(Duration::from_secs(1), rx.recv()) + .await + .expect("a counted datagram was not delivered") + .expect("packet channel closed"); + assert_eq!(packet.transport_id, transport_id); + } + node.clear_connected_udp_for_peer(&node_addr); + for (_, t) in node.transports.iter_mut() { + t.stop().await.ok(); + } +} + +/// A promoted peer reached over a real UDP transport on loopback, with an +/// encrypt worker pool, so the node's sends to it take the worker path +/// rather than `UdpTransport::send_async`. Returns the node, the peer's +/// address, the UDP transport's stats, and the plain socket standing in +/// for the peer. +#[cfg(unix)] +async fn peer_behind_the_encrypt_workers() -> ( + Node, + NodeAddr, + std::sync::Arc, + std::net::UdpSocket, +) { + use crate::config::UdpConfig; + use crate::transport::udp::UdpTransport; + + let transport_id = TransportId::new(1); + let (mut node, node_addr, _, _) = promoted_peer_with_the_far_side_session(transport_id); + let (tx, _rx) = packet_channel(64); + let udp_cfg = UdpConfig { + bind_addr: Some("127.0.0.1:0".to_string()), + ..Default::default() + }; + let mut udp = UdpTransport::new(transport_id, None, udp_cfg, tx); + udp.start_async().await.unwrap(); + let stats = udp.stats().clone(); + node.transports + .insert(transport_id, TransportHandle::Udp(udp)); + node.supervisor.encrypt_workers = + Some(crate::node::encrypt_worker::EncryptWorkerPool::spawn(1)); + + let remote = std::net::UdpSocket::bind("127.0.0.1:0").unwrap(); + remote + .set_read_timeout(Some(Duration::from_secs(2))) + .unwrap(); + node.get_peer_mut(&node_addr).unwrap().set_current_addr( + transport_id, + TransportAddr::from_string(&remote.local_addr().unwrap().to_string()), + ); + (node, node_addr, stats, remote) +} + +/// Wait for the encrypt worker to count `sent` datagrams, then a little +/// longer so a second count of any of them would show. The worker counts +/// after its send returns, so a datagram can reach the peer just before +/// its count lands. +#[cfg(unix)] +fn settle_sent(stats: &crate::transport::udp::UdpStats, sent: u64) { + let deadline = std::time::Instant::now() + Duration::from_secs(2); + while stats.snapshot().packets_sent < sent && std::time::Instant::now() < deadline { + std::thread::sleep(Duration::from_millis(5)); + } + std::thread::sleep(Duration::from_millis(50)); +} + +/// A link message the encrypt worker sends counts once in the UDP +/// transport's own stats, whether it leaves on the wildcard socket or on +/// the peer's connected socket: `packets_sent` means datagrams sent on +/// this transport, and the worker's sends never pass through +/// `UdpTransport::send_async`, which counts the rest. +#[cfg(any(target_os = "linux", target_os = "macos"))] +#[tokio::test] +async fn a_link_message_the_encrypt_worker_sends_counts_once_in_the_udp_transport_stats() { + let (mut node, node_addr, stats, remote) = peer_behind_the_encrypt_workers().await; + let mut buf = [0u8; 2048]; + // One tick publishes the transport rows `show transports` serves off + // the rx loop; no tick runs after this. + node.record_stats_history(); + let handle = node.control_read_handle(); + + node.send_encrypted_link_message(&node_addr, &[0x51]) + .await + .expect("send on the wildcard socket"); + let (wildcard_len, _) = remote.recv_from(&mut buf).expect("the peer receives it"); + settle_sent(&stats, 1); + let counted = stats.snapshot(); + assert_eq!( + counted.packets_sent, 1, + "a datagram the worker sent on the wildcard socket must count once" + ); + assert_eq!(counted.bytes_sent, wildcard_len as u64); + + node.activate_connected_udp_sessions().await; + assert!( + node.get_peer(&node_addr).unwrap().connected_udp().is_some(), + "precondition: the tick activation installed a connected socket" + ); + node.send_encrypted_link_message(&node_addr, &[0x51]) + .await + .expect("send on the connected socket"); + let (connected_len, _) = remote.recv_from(&mut buf).expect("the peer receives it"); + settle_sent(&stats, 2); + let counted = stats.snapshot(); + assert_eq!( + counted.packets_sent, 2, + "a datagram the worker sent on the connected socket must count once" + ); + assert_eq!(counted.bytes_sent, (wildcard_len + connected_len) as u64); + assert_eq!(counted.send_errors, 0); + + // `show transports`, on the rx loop and off it, reports the same counts. + let off_loop = crate::control::queries::show_transports_from_handle(&handle); + assert_eq!(off_loop, crate::control::queries::show_transports(&node)); + let row = off_loop["transports"] + .as_array() + .unwrap() + .iter() + .find(|t| t["transport_id"] == 1) + .unwrap_or_else(|| panic!("no row for the UDP transport: {off_loop}")) + .clone(); + assert_eq!( + row["stats"]["packets_sent"], 2, + "show transports must report the datagrams the worker sent" + ); + assert_eq!( + row["stats"]["bytes_sent"], + (wildcard_len + connected_len) as u64 + ); + + node.clear_connected_udp_for_peer(&node_addr); + for (_, t) in node.transports.iter_mut() { + t.stop().await.ok(); + } +} + +/// Session data takes the pipelined path, where the worker seals both +/// layers and sends; its datagram counts once in the UDP transport's +/// stats, as a link message's does. +#[cfg(unix)] +#[tokio::test] +async fn session_data_the_encrypt_worker_sends_counts_once_in_the_udp_transport_stats() { + use crate::node::session::{EndToEndState, SessionEntry}; + + let (mut node, node_addr, stats, remote) = peer_behind_the_encrypt_workers().await; + let far_side = Identity::generate(); + let session = super::session::make_noise_session(node.identity(), &far_side); + node.sessions.insert( + node_addr, + SessionEntry::new( + node_addr, + far_side.pubkey_full(), + EndToEndState::Established(session), + 1_000, + true, + ), + ); + + node.send_session_data(&node_addr, 0, 0, b"counted once") + .await + .expect("send session data"); + let mut buf = [0u8; 2048]; + let (len, _) = remote.recv_from(&mut buf).expect("the peer receives it"); + settle_sent(&stats, 1); + let counted = stats.snapshot(); + assert_eq!( + counted.packets_sent, 1, + "a session datagram the worker sent must count once" + ); + assert_eq!(counted.bytes_sent, len as u64); + assert_eq!(counted.send_errors, 0); + + for (_, t) in node.transports.iter_mut() { + t.stop().await.ok(); + } +} diff --git a/src/node/tests/control.rs b/src/node/tests/control.rs index dbb08b99..2cc1042f 100644 --- a/src/node/tests/control.rs +++ b/src/node/tests/control.rs @@ -529,3 +529,101 @@ fn peer_connectivity_turns_stale_one_millisecond_past_the_heartbeat_interval() { assert_eq!(at(&node, seen + 1_000), ConnectivityState::Connected); assert_eq!(at(&node, seen + 1_001), ConnectivityState::Stale); } + +/// `show_transports` served off the rx loop reports the transport counters +/// as they are now, not as the last tick published them: a counter that +/// moves after the publish shows up without another tick, in the same +/// fields and shape the on-loop render gives. +#[tokio::test] +async fn show_transports_off_loop_reports_counters_that_moved_since_the_last_tick() { + use crate::config::{TcpConfig, UdpConfig}; + use crate::control::queries::{show_transports, show_transports_from_handle}; + use crate::transport::tcp::TcpTransport; + use crate::transport::udp::UdpTransport; + + let mut node = make_node(); + let (tx, _rx) = packet_channel(16); + let udp_cfg = UdpConfig { + bind_addr: Some("127.0.0.1:0".to_string()), + ..Default::default() + }; + let mut udp = UdpTransport::new(TransportId::new(1), None, udp_cfg, tx.clone()); + udp.start_async().await.unwrap(); + let udp_stats = udp.stats().clone(); + let tcp_cfg = TcpConfig { + bind_addr: Some("127.0.0.1:0".to_string()), + ..Default::default() + }; + let mut tcp = TcpTransport::new(TransportId::new(2), None, tcp_cfg, tx); + tcp.start_async().await.unwrap(); + let tcp_stats = tcp.stats().clone(); + node.transports + .insert(TransportId::new(1), TransportHandle::Udp(udp)); + node.transports + .insert(TransportId::new(2), TransportHandle::Tcp(tcp)); + + // One tick publishes the transport rows. + node.record_stats_history(); + let handle = node.control_read_handle(); + let published = std::sync::Arc::clone(&*handle.entities()); + let row = |v: &serde_json::Value, id: u32| { + v["transports"] + .as_array() + .unwrap() + .iter() + .find(|t| t["transport_id"] == id) + .unwrap_or_else(|| panic!("no row for transport {id}: {v}")) + .clone() + }; + let before = show_transports_from_handle(&handle); + assert_eq!(row(&before, 1)["stats"]["packets_recv"], 0); + assert_eq!(row(&before, 2)["stats"]["connect_timeouts"], 0); + + // The counters move; no tick runs. + for _ in 0..3 { + udp_stats.record_recv(100); + } + tcp_stats.record_connect_timeout(); + tcp_stats.record_connect_refused(); + + let after = show_transports_from_handle(&handle); + assert!( + std::sync::Arc::ptr_eq(&published, &handle.entities()), + "precondition: nothing republished the snapshot" + ); + let udp_row = row(&after, 1); + let tcp_row = row(&after, 2); + assert_eq!( + udp_row["stats"]["packets_recv"], 3, + "off-loop show_transports did not see the UDP counter move" + ); + assert_eq!(udp_row["stats"]["bytes_recv"], 300); + assert_eq!( + tcp_row["stats"]["connect_timeouts"], 1, + "off-loop show_transports did not see the TCP counter move" + ); + assert_eq!(tcp_row["stats"]["connect_refused"], 1); + + // Same fields and shape as before: each block is its stats snapshot + // serialized whole, and the whole render matches the on-loop one. + assert_eq!( + udp_row["stats"], + serde_json::to_value(udp_stats.snapshot()).unwrap() + ); + assert_eq!( + tcp_row["stats"], + serde_json::to_value(tcp_stats.snapshot()).unwrap() + ); + assert_eq!(after, show_transports(&node)); + let keys = |v: &serde_json::Value| { + let mut k: Vec = v.as_object().unwrap().keys().cloned().collect(); + k.sort(); + k + }; + assert_eq!(keys(&udp_row), keys(&row(&before, 1))); + assert_eq!(keys(&tcp_row["stats"]), keys(&row(&before, 2)["stats"])); + + for (_, t) in node.transports.iter_mut() { + t.stop().await.ok(); + } +} diff --git a/src/node/tests/mod.rs b/src/node/tests/mod.rs index b57b0d33..8d693f94 100644 --- a/src/node/tests/mod.rs +++ b/src/node/tests/mod.rs @@ -24,6 +24,7 @@ mod heartbeat; mod mmp_chartests; mod probe; mod routing; +mod rx_stall; mod session; mod spanning_tree; mod tcp; diff --git a/src/node/tests/rx_stall.rs b/src/node/tests/rx_stall.rs new file mode 100644 index 00000000..7c842efd --- /dev/null +++ b/src/node/tests/rx_stall.rs @@ -0,0 +1,1310 @@ +//! A handshake send to a TCP connection that has gone away must not dial. +//! +//! When a msg1 arrives on an inbound TCP connection that has since closed, +//! the reply has nowhere to go. The handlers that answer it run inline on the +//! rx loop, so a reply that fell through to TCP connect-on-send held every +//! other frame the loop owns, including frames that arrived on UDP, for the +//! whole connect timeout. The tick's handshake sends (the rekey msg1 and its +//! resends, the msg1 resend on an outbound handshake), the executor's msg1 +//! send and the encrypted link send are awaited by the same loop and had +//! the same exposure. These tests assert each send now fails at once +//! instead: no connect attempt is counted and the call returns well inside +//! a bound far below the timeout. Each one also runs a healthy control, so a +//! run that skips the send path entirely fails too. +//! +//! The tick and dial-path sends may start a background connect, but only to +//! an address this node dialed; the tests check that it starts there, that +//! it does not start toward an inbound peer's address, and that a later send +//! uses the connection once it is up. +//! +//! The unanswered SYN is constructed locally: a listener with a backlog of +//! zero whose single accept slot is already taken. Linux drops further SYNs to +//! a listener whose accept queue is full, so a connect to it times out rather +//! than being refused. `Blackhole::silent()` checks that before any test +//! relies on it, which is what lets a regression show up at its real size: +//! one connect timeout per reply, counted in `connect_timeouts`. +//! +//! The tests print their measurements; run with `--nocapture` to see them. + +use super::*; +use crate::config::{TcpConfig, UdpConfig}; +use crate::peer::machine::{PeerEvent, PeerMachine, TimerKind}; +use crate::proto::fmp::wire::{CommonPrefix, PHASE_MSG1, PHASE_MSG2, build_msg1}; +use crate::proto::link::LinkMessageType; +use crate::testutil::Blackhole; +use crate::transport::tcp::TcpTransport; +use crate::transport::tcp::stats::TcpStatsSnapshot; +use crate::transport::udp::UdpTransport; +use crate::transport::{ConnectionState, PacketTx, TransportHandle, TransportId}; +use std::io::Read; +use std::net::SocketAddr; +use std::time::Instant; +use tokio::io::{AsyncReadExt, AsyncWriteExt}; +use tokio::time::timeout; + +const UDP_ID: u32 = 1; +const TCP_ID: u32 = 2; +const EPOCH: [u8; 8] = [7u8; 8]; + +/// The connect timeout every dead-link test runs at: the shipped default, so +/// a send that dials shows up at the size it has in the field. +const CONNECT_TIMEOUT_MS: u64 = 5000; + +/// How long a handler answering a dead link may take. Far below any connect +/// timeout, far above the microseconds a failed pool lookup costs. +const BOUND: Duration = Duration::from_millis(250); + +/// A genuine wire msg1 from `sender` to `node`. +fn craft_msg1(node: &Node, sender: &Identity, sender_index: u32) -> Vec { + let target = PeerIdentity::from_pubkey_full(node.identity().pubkey_full()); + let mut conn = outbound_leg(LinkId::new(0x5EED), target, 1000); + let noise_msg1 = conn + .start_handshake(sender.keypair(), EPOCH, 1000) + .expect("start_handshake produces noise msg1"); + build_msg1(SessionIndex::new(sender_index), &noise_msg1) +} + +/// A node with a UDP and a TCP transport feeding one packet channel, as a +/// node built from config has. Returns the node, a sender into that channel +/// (to inject frames as if a transport had delivered them), and the UDP +/// transport's local address. +async fn node_with_udp_and_tcp(connect_timeout_ms: u64) -> (Node, PacketTx, SocketAddr) { + let mut node = make_node(); + let (tx, rx) = packet_channel(1024); + + let udp_cfg = UdpConfig { + bind_addr: Some("127.0.0.1:0".to_string()), + mtu: Some(1280), + ..Default::default() + }; + let mut udp = UdpTransport::new(TransportId::new(UDP_ID), None, udp_cfg, tx.clone()); + udp.start_async().await.unwrap(); + let udp_addr = udp.local_addr().unwrap(); + + let tcp_cfg = TcpConfig { + bind_addr: Some("127.0.0.1:0".to_string()), + mtu: Some(1400), + connect_timeout_ms: Some(connect_timeout_ms), + ..Default::default() + }; + let mut tcp = TcpTransport::new(TransportId::new(TCP_ID), None, tcp_cfg, tx.clone()); + tcp.start_async().await.unwrap(); + + node.transports + .insert(TransportId::new(UDP_ID), TransportHandle::Udp(udp)); + node.transports + .insert(TransportId::new(TCP_ID), TransportHandle::Tcp(tcp)); + node.packet_rx = Some(rx); + node.supervisor.state = NodeState::Running; + (node, tx, udp_addr) +} + +/// The node's TCP transport. +fn tcp(node: &Node) -> &TransportHandle { + node.transports + .get(&TransportId::new(TCP_ID)) + .expect("no TCP transport") +} + +/// The TCP transport's live counters. +fn tcp_stats(node: &Node) -> TcpStatsSnapshot { + match tcp(node) { + TransportHandle::Tcp(t) => t.stats().snapshot(), + _ => panic!("transport {TCP_ID} is not TCP"), + } +} + +/// Stop every transport the node holds. +async fn stop_all(node: &mut Node) { + for (_, t) in node.transports.iter_mut() { + t.stop().await.ok(); + } +} + +/// Wait until the TCP transport holds no connection to `addr`. +async fn wait_pool_gone(node: &Node, addr: &TransportAddr) { + let start = Instant::now(); + while tcp(node).connection_state(addr) != ConnectionState::None { + assert!( + start.elapsed() < Duration::from_secs(3), + "pool entry for {addr} never dropped" + ); + tokio::time::sleep(Duration::from_millis(10)).await; + } +} + +/// Open a connection from the node to `bh`'s free accept slot, the way a +/// node ends up holding a live connection to a peer's address, and return +/// the far end of it. +async fn prime_link(node: &Node, bh: &Blackhole) -> std::net::TcpStream { + let addr = bh.transport_addr(); + tcp(node).connect(&addr).await.unwrap(); + let start = Instant::now(); + while tcp(node).connection_state(&addr) != ConnectionState::Connected { + assert!( + start.elapsed() < Duration::from_secs(3), + "connection to {addr} never came up" + ); + tokio::time::sleep(Duration::from_millis(10)).await; + } + let (accepted, _) = bh.listener.accept().unwrap(); + let accepted = std::net::TcpStream::from(accepted); + accepted + .set_read_timeout(Some(Duration::from_millis(1000))) + .unwrap(); + accepted +} + +/// Close the node's connection to `bh` from the far end, after taking the +/// listener's accept slot so that any later dial to the address hangs. +async fn kill_link(node: &Node, bh: &mut Blackhole, accepted: std::net::TcpStream) { + bh.fill(); + drop(accepted); + wait_pool_gone(node, &bh.transport_addr()).await; +} + +/// Read one frame's worth of bytes the node wrote to `far_end`, if any +/// arrive within its read timeout. +fn read_frame(far_end: &mut std::net::TcpStream) -> Option> { + let mut buf = [0u8; 2048]; + match far_end.read(&mut buf) { + Ok(n) if n > 0 => Some(buf[..n].to_vec()), + _ => None, + } +} + +/// What one handler call against a TCP reply address did. +#[derive(Debug)] +struct Reply { + elapsed: Duration, + connect_timeouts: u64, + connect_refused: u64, + connections_established: u64, +} + +/// One call into a node that may send on TCP. +enum Trigger { + /// A frame for the packet handler. + Packet(ReceivedPacket), + /// The tick's rekey msg1 check. + RekeyCheck, + /// The tick's rekey msg1 resend, with every resend due. + RekeyResend, + /// The tick's handshake timers, at this time. + PeerTimers(u64), + /// The executor's send of the msg1 armed on this outbound link. + StoredMsg1(LinkId, TransportAddr), + /// An encrypted link message (a heartbeat) to this peer. + LinkMessage(NodeAddr), +} + +/// Fire `trigger` once and measure it against the TCP counters. +async fn timed_fire(node: &mut Node, trigger: Trigger) -> Reply { + let before = tcp_stats(node); + let t0 = Instant::now(); + match trigger { + Trigger::Packet(packet) => node.process_packet(packet).await, + Trigger::RekeyCheck => node.check_rekey().await, + Trigger::RekeyResend => node.resend_pending_rekeys(Node::now_ms() + 60_000).await, + Trigger::PeerTimers(now_ms) => node.drive_peer_timers(now_ms).await, + Trigger::StoredMsg1(link, addr) => { + node.send_stored_msg1(link, TransportId::new(TCP_ID), &addr, Node::now_ms()) + .await + } + Trigger::LinkMessage(peer) => { + let heartbeat = [LinkMessageType::Heartbeat.to_byte()]; + let _ = node.send_encrypted_link_message(&peer, &heartbeat).await; + } + } + let elapsed = t0.elapsed(); + let after = tcp_stats(node); + Reply { + elapsed, + connect_timeouts: after.connect_timeouts - before.connect_timeouts, + connect_refused: after.connect_refused - before.connect_refused, + connections_established: after.connections_established - before.connections_established, + } +} + +/// Run `process_packet` once and measure it against the TCP counters. +async fn timed_process(node: &mut Node, packet: ReceivedPacket) -> Reply { + timed_fire(node, Trigger::Packet(packet)).await +} + +/// Every way a reply to a dead link failed to be fast and dial-free. +fn dial_findings(what: &str, r: &Reply) -> Vec { + let mut found = Vec::new(); + if r.elapsed >= BOUND { + found.push(format!( + "{what}: handler took {:?} (bound {BOUND:?}); a connect timeout is {CONNECT_TIMEOUT_MS} ms", + r.elapsed + )); + } + if r.connect_timeouts != 0 { + found.push(format!("{what}: {} connect timeouts", r.connect_timeouts)); + } + if r.connect_refused != 0 { + found.push(format!("{what}: {} connects refused", r.connect_refused)); + } + if r.connections_established != 0 { + found.push(format!( + "{what}: {} connections dialed", + r.connections_established + )); + } + found +} + +/// Assert a reply to a dead link failed at once and attempted no connect. +fn assert_no_dial(what: &str, r: &Reply) { + let found = dial_findings(what, r); + assert!(found.is_empty(), "{}", found.join("; ")); +} + +/// A real TCP client connected to the node's listener that has sent one +/// msg1. Returns the client and the frame as the node's receive task +/// delivered it, which carries the client's address as the reply address. +async fn msg1_over_real_tcp(node: &mut Node) -> (tokio::net::TcpStream, ReceivedPacket) { + let listen = tcp(node).local_addr().expect("TCP listener bound"); + let mut client = tokio::net::TcpStream::connect(listen).await.unwrap(); + let data = craft_msg1(node, &Identity::generate(), 0x51); + client.write_all(&data).await.unwrap(); + let rx = node.packet_rx.as_mut().expect("packet channel"); + let packet = timeout(Duration::from_secs(2), rx.recv()) + .await + .expect("msg1 never reached the packet channel") + .expect("packet channel closed"); + assert_eq!(packet.transport_id, TransportId::new(TCP_ID)); + (client, packet) +} + +/// Whether `client` receives a msg2 within a second. +async fn client_gets_msg2(client: &mut tokio::net::TcpStream) -> bool { + let mut buf = [0u8; 2048]; + match timeout(Duration::from_secs(1), client.read(&mut buf)).await { + Ok(Ok(n)) if n > 0 => CommonPrefix::parse(&buf[..n]).is_some_and(|p| p.phase == PHASE_MSG2), + _ => false, + } +} + +/// A msg2 reply whose TCP connection is gone fails at once, attempts no +/// connect, and tears down the half-built link. A msg1 on a live inbound +/// connection is still answered on that connection. +#[tokio::test] +async fn msg2_reply_to_dead_tcp_link_returns_without_dialing() { + // Control: a live inbound connection gets its msg2. + let (mut node, _tx, _) = node_with_udp_and_tcp(CONNECT_TIMEOUT_MS).await; + let (mut client, packet) = msg1_over_real_tcp(&mut node).await; + let r = timed_process(&mut node, packet).await; + let answered = client_gets_msg2(&mut client).await; + println!("msg2 control live inbound connection: {r:?}, msg2 received {answered}"); + assert_no_dial("msg2 control", &r); + assert!(answered, "control: the live connection got no msg2"); + assert_eq!(node.peer_count(), 1, "control should promote the peer"); + stop_all(&mut node).await; + + // The reply address has no connection and does not answer SYNs. + let bh = Blackhole::silent(); + let (mut node, _tx, _) = node_with_udp_and_tcp(CONNECT_TIMEOUT_MS).await; + let data = craft_msg1(&node, &Identity::generate(), 0x11); + let packet = ReceivedPacket::new(TransportId::new(TCP_ID), bh.transport_addr(), data); + let r = timed_process(&mut node, packet).await; + println!("msg2 dead blackholed reply address: {r:?}"); + assert_no_dial("msg2 to a dead link", &r); + assert_eq!( + node.peer_count(), + 0, + "a failed msg2 send discards the handshake" + ); + assert!(node.links.is_empty(), "the half-built link is torn down"); + assert!( + node.addr_to_link.is_empty(), + "the half-built link is unindexed" + ); + stop_all(&mut node).await; +} + +/// Establish a peer on TCP at `bh`'s address over a live connection the node +/// holds there. Returns the node, the peer's identity and address, and the +/// far end of the connection. +async fn peer_on_tcp(bh: &Blackhole) -> (Node, Identity, NodeAddr, std::net::TcpStream) { + let (mut node, _tx, _) = node_with_udp_and_tcp(CONNECT_TIMEOUT_MS).await; + let mut far_end = prime_link(&node, bh).await; + let sender = Identity::generate(); + let sender_addr = *PeerIdentity::from_pubkey_full(sender.pubkey_full()).node_addr(); + let link = bh.transport_addr(); + + let data = craft_msg1(&node, &sender, 0x01); + node.process_packet(ReceivedPacket::new( + TransportId::new(TCP_ID), + link.clone(), + data, + )) + .await; + assert_eq!(node.peer_count(), 1, "peer established over TCP"); + let p = node.get_peer(&sender_addr).unwrap(); + assert_eq!(p.transport_id(), Some(TransportId::new(TCP_ID))); + assert_eq!(p.current_addr(), Some(&link)); + assert!( + read_frame(&mut far_end).is_some(), + "the msg2 went out on the connection" + ); + (node, sender, sender_addr, far_end) +} + +/// An address the peer's later frames arrive from: a new connection, with no +/// pool entry of its own. +fn elsewhere() -> TransportAddr { + TransportAddr::from_string("127.0.0.1:9") +} + +/// Record `peer`'s link as one this node dialed at the address it holds, +/// as if the node had been the initiator. +fn make_link_outbound(node: &mut Node, peer: &NodeAddr) { + let link_id = node.get_peer(peer).unwrap().link_id(); + let old = node.links.get(&link_id).expect("the peer's link"); + let link = Link::new( + link_id, + old.transport_id(), + old.remote_addr().clone(), + LinkDirection::Outbound, + old.base_rtt(), + ); + node.links.insert(link_id, link); +} + +/// Age `peer`'s session past the rekey trigger of a default config. +fn age_past_rekey(node: &mut Node, peer: &NodeAddr) { + let after = node.config().node.rekey.after_secs + crate::node::REKEY_JITTER_SECS as u64 + 1; + node.get_peer_mut(peer) + .unwrap() + .test_backdate_session_established(Duration::from_secs(after)); +} + +/// Arm an outbound handshake to `addr` on TCP as a dial does: a link this +/// node dialed, a machine that has sent its msg1 and holds the wire, and a +/// retransmit timer due at `due_ms`. Returns the link and the msg1 wire. +fn dial_leg(node: &mut Node, addr: &TransportAddr, now_ms: u64, due_ms: u64) -> (LinkId, Vec) { + let tcp_id = TransportId::new(TCP_ID); + let target = PeerIdentity::from_pubkey_full(Identity::generate().pubkey_full()); + let link_id = node.allocate_link_id(); + let mut leg = outbound_leg(link_id, target, now_ms); + let our_index = node.index_allocator.allocate().unwrap(); + let noise_msg1 = leg + .start_handshake(node.identity().keypair(), node.startup_epoch(), now_ms) + .unwrap(); + let wire = build_msg1(our_index, &noise_msg1); + node.links.insert( + link_id, + Link::new( + link_id, + tcp_id, + addr.clone(), + LinkDirection::Outbound, + Duration::from_millis(100), + ), + ); + node.addr_to_link.insert((tcp_id, addr.clone()), link_id); + node.pending_outbound + .insert((tcp_id, our_index.as_u32()), link_id); + let mut machine = PeerMachine::new_outbound(link_id, target, now_ms); + let _ = machine.step( + PeerEvent::Dial { + transport_id: tcp_id, + remote_addr: addr.clone(), + peer_identity: target, + connection_oriented: false, + }, + now_ms, + &mut node.index_allocator, + ); + machine.set_conn_handshake_msg1(wire.clone(), due_ms); + machine.set_conn_our_index(our_index); + machine.set_conn_transport_id(tcp_id); + machine.set_conn_source_addr(addr.clone()); + machine.set_leg(leg.take_leg().unwrap()); + assert!(machine.is_handshaking_sent_msg1()); + node.peer_machines.insert(link_id, machine); + node.peer_timers + .entry(link_id) + .or_default() + .insert(TimerKind::HandshakeRetransmit, due_ms); + (link_id, wire) +} + +/// Whether `frame` is a handshake msg1. +fn is_msg1(frame: &[u8]) -> bool { + CommonPrefix::parse(frame).is_some_and(|p| p.phase == PHASE_MSG1) +} + +/// What a tick's rekey check did to a TCP peer. +#[derive(Debug)] +struct RekeyStart { + reply: Reply, + /// The rekey msg1 went out and the cycle is in flight. + started: bool, + /// The far end received the msg1. + delivered: bool, + /// The transport's connection state for the peer's address afterwards. + state: ConnectionState, +} + +/// Run the tick's rekey check for a TCP peer due to rekey, whose link is +/// alive or (with `dead`) closed, and which this node dialed (`outbound`) +/// or accepted. +async fn rekey_start(dead: bool, outbound: bool) -> RekeyStart { + let mut bh = Blackhole::open(false); + let (mut node, _sender, sender_addr, far_end) = peer_on_tcp(&bh).await; + if outbound { + make_link_outbound(&mut node, &sender_addr); + } + let mut far_end = if dead { + kill_link(&node, &mut bh, far_end).await; + None + } else { + Some(far_end) + }; + age_past_rekey(&mut node, &sender_addr); + let reply = timed_fire(&mut node, Trigger::RekeyCheck).await; + let started = node + .get_peer(&sender_addr) + .is_some_and(|p| p.rekey_in_progress()); + let delivered = far_end + .as_mut() + .and_then(read_frame) + .is_some_and(|f| is_msg1(&f)); + let state = tcp(&node).connection_state(&bh.transport_addr()); + stop_all(&mut node).await; + RekeyStart { + reply, + started, + delivered, + state, + } +} + +/// The tick's rekey msg1 to a TCP peer whose connection has closed fails at +/// once without dialing. A background connect is started toward a peer this +/// node dialed, and never toward an inbound peer's address. With the link +/// alive the msg1 goes out and the cycle starts. +#[tokio::test] +async fn rekey_msg1_to_dead_tcp_link_does_not_hold_tick() { + let r = rekey_start(false, false).await; + println!("rekey msg1 control link alive: {r:?}"); + assert_no_dial("rekey msg1 control", &r.reply); + assert!( + r.started && r.delivered, + "control: the rekey msg1 did not go out" + ); + + let r = rekey_start(true, false).await; + println!("rekey msg1 dead inbound peer: {r:?}"); + assert_no_dial("rekey msg1 to a closed inbound link", &r.reply); + assert!(!r.started, "a failed rekey msg1 starts no cycle"); + assert_eq!( + r.state, + ConnectionState::None, + "a connect was started toward an inbound peer's address" + ); + + let r = rekey_start(true, true).await; + println!("rekey msg1 dead outbound peer: {r:?}"); + assert_no_dial("rekey msg1 to a closed outbound link", &r.reply); + assert!(!r.started, "a failed rekey msg1 starts no cycle"); + assert_eq!( + r.state, + ConnectionState::Connecting, + "no background connect toward the address this node dialed" + ); +} + +/// The tick's msg1 resend on an outbound handshake whose address does not +/// answer fails at once without dialing and starts a background connect. +/// Once the address answers and that connect finishes, a later tick sends +/// the msg1 on it: the connection is not left stranded unused. +#[tokio::test] +async fn msg1_resend_to_dead_outbound_leg_recovers_after_background_connect() { + let mut bh = Blackhole::silent(); + let (mut node, _tx, _) = node_with_udp_and_tcp(CONNECT_TIMEOUT_MS).await; + let addr = bh.transport_addr(); + let now_ms = Node::now_ms(); + let (link, wire) = dial_leg(&mut node, &addr, now_ms, now_ms + 1000); + + let r = timed_fire(&mut node, Trigger::PeerTimers(now_ms + 1000)).await; + println!("msg1 resend blackholed dial address: {r:?}"); + assert_no_dial("msg1 resend to a dead outbound leg", &r); + assert_eq!(node.connection_resend_count(link), 0, "nothing was sent"); + assert_eq!( + tcp(&node).connection_state(&addr), + ConnectionState::Connecting, + "no background connect toward the dial address" + ); + + // The address starts answering: empty the accept queue, and the + // background connect's retransmitted SYN completes. + let _filler_ends = bh.drain(); + let start = Instant::now(); + let mut tick = 1; + while node.connection_resend_count(link) == 0 { + assert!( + start.elapsed() < Duration::from_secs(4), + "the msg1 resend never went out over the background connect" + ); + tokio::time::sleep(Duration::from_millis(100)).await; + let r = timed_fire(&mut node, Trigger::PeerTimers(now_ms + 1000 + tick * 100)).await; + tick += 1; + assert!(r.elapsed < BOUND, "a tick took {:?}", r.elapsed); + assert_eq!(r.connect_timeouts, 0, "a tick dialed and timed out"); + } + let (accepted, _) = bh.listener.accept().unwrap(); + let mut accepted = std::net::TcpStream::from(accepted); + accepted + .set_read_timeout(Some(Duration::from_millis(1000))) + .unwrap(); + println!( + "msg1 resend sent after {:?} over the background connect", + start.elapsed() + ); + assert_eq!( + read_frame(&mut accepted), + Some(wire), + "the msg1 did not arrive on the background connection" + ); + stop_all(&mut node).await; +} + +/// Run a same-epoch rekey msg1 for a peer whose established TCP link is gone +/// (or, with `dead` false, still connected). Returns the measurement and +/// whether a pending session was stored. +async fn rekey_reply(dead: bool) -> (Reply, bool) { + let mut bh = Blackhole::open(false); + let (mut node, sender, sender_addr, far_end) = peer_on_tcp(&bh).await; + let _far_end = if dead { + kill_link(&node, &mut bh, far_end).await; + None + } else { + Some(far_end) + }; + node.get_peer_mut(&sender_addr) + .unwrap() + .test_backdate_session_established(Duration::from_secs(31)); + + // The peer has come back on a new connection and sends a rekey msg1 at + // the same epoch. The rekey msg2 goes to the established link's address. + let data = craft_msg1(&node, &sender, 0x02); + let r = timed_process( + &mut node, + ReceivedPacket::new(TransportId::new(TCP_ID), elsewhere(), data), + ) + .await; + let pending = node + .get_peer(&sender_addr) + .is_some_and(|p| p.pending_new_session().is_some()); + stop_all(&mut node).await; + (r, pending) +} + +/// A rekey msg2 to a peer whose established TCP link has closed +/// fails at once and stores no pending session; with the link alive the +/// pending session is stored. +#[tokio::test] +async fn rekey_msg2_to_closed_tcp_link_returns_without_dialing() { + let (r, pending) = rekey_reply(false).await; + println!("rekey control link alive: {r:?}, pending session {pending}"); + assert_no_dial("rekey control", &r); + assert!(pending, "control should store the rekey session"); + + let (r, pending) = rekey_reply(true).await; + println!("rekey dead link closed: {r:?}, pending session {pending}"); + assert_no_dial("rekey msg2 to a closed link", &r); + assert!(!pending, "a failed rekey msg2 send stores no session"); +} + +/// Run the node's real rx loop, inject `poisoned` TCP msg1 frames whose reply +/// address is blackholed, then send one genuine msg1 over UDP and return how +/// long the UDP initiator waits for its msg2. +async fn udp_msg2_latency(connect_timeout_ms: u64, poisoned: usize) -> Duration { + let (mut node, tx, udp_addr) = node_with_udp_and_tcp(connect_timeout_ms).await; + let holes: Vec = (0..poisoned).map(|_| Blackhole::silent()).collect(); + let poison: Vec = holes + .iter() + .enumerate() + .map(|(i, bh)| { + let data = craft_msg1(&node, &Identity::generate(), 0x100 + i as u32); + ReceivedPacket::new(TransportId::new(TCP_ID), bh.transport_addr(), data) + }) + .collect(); + let udp_msg1 = craft_msg1(&node, &Identity::generate(), 0x200); + let peer = tokio::net::UdpSocket::bind("127.0.0.1:0").await.unwrap(); + + // Long enough to measure a regression, one timeout per poisoned frame, + // rather than only reporting that it was slow. + let budget = Duration::from_millis(connect_timeout_ms * poisoned as u64 + 3000); + let measure = async { + for p in poison { + tx.send(p).await.unwrap(); + } + // Let the loop pick up the TCP frames before the UDP one arrives. + tokio::time::sleep(Duration::from_millis(20)).await; + let t0 = Instant::now(); + peer.send_to(&udp_msg1, udp_addr).await.unwrap(); + let mut buf = [0u8; 2048]; + loop { + let (n, _) = timeout(budget, peer.recv_from(&mut buf)) + .await + .expect("no msg2 over UDP within budget") + .unwrap(); + if CommonPrefix::parse(&buf[..n]).is_some_and(|p| p.phase == PHASE_MSG2) { + return t0.elapsed(); + } + } + }; + + let latency = tokio::select! { + r = node.run_rx_loop() => panic!("rx loop exited: {r:?}"), + l = measure => l, + }; + stop_all(&mut node).await; + drop(holes); + latency +} + +/// Inside the real rx loop, a UDP initiator's msg2 does not wait +/// behind TCP msg1s whose replies have nowhere to go. +#[tokio::test] +async fn udp_handshake_is_not_delayed_by_dead_tcp_replies_in_rx_loop() { + for poisoned in [0usize, 3] { + let latency = udp_msg2_latency(CONNECT_TIMEOUT_MS, poisoned).await; + println!( + "rx loop connect_timeout_ms={CONNECT_TIMEOUT_MS} blackholed TCP msg1 ahead={poisoned}: UDP msg2 after {latency:?}" + ); + assert!( + latency < BOUND, + "UDP msg2 took {latency:?} behind {poisoned} dead TCP replies (bound {BOUND:?})" + ); + } +} + +/// A counter from the off-loop `show_transports` view. +fn snapshot_stat( + handle: &crate::control::read_handle::ControlReadHandle, + id: u32, + key: &str, +) -> u64 { + let v = crate::control::queries::show_transports_from_handle(handle); + v["transports"] + .as_array() + .unwrap() + .iter() + .find(|t| t["transport_id"] == id) + .and_then(|t| t["stats"][key].as_u64()) + .unwrap_or_else(|| panic!("no stats.{key} for transport {id}: {v}")) +} + +/// The longest the tick may go without publishing during the burst. It +/// runs every second, so a longer gap means a tick was held. +const SNAPSHOT_LAG: Duration = Duration::from_millis(1500); + +/// What the off-loop view and the tick did during a burst of UDP traffic. +#[derive(Debug)] +struct TickProgress { + /// UDP frames sent during the burst. + sent: u64, + /// Off-loop reads of UDP `packets_recv` taken once traffic had arrived. + checks: usize, + /// The reads that fell outside the live count sampled just before and + /// just after, as (ms into the burst, live before, view, live after). + off: Vec<(u128, u64, u64, u64)>, + /// Entity snapshot publishes seen during the burst. + publishes: usize, + /// The longest stretch of the burst with no publish, counting from its + /// start and to its end. + max_gap: Duration, + /// Off-loop TCP `connect_timeouts` at the end of the burst. + snapshot_timeouts: u64, + /// Live TCP `connect_timeouts` at the end of the burst. + live_timeouts: u64, +} + +/// Queue `poisoned` TCP msg1s whose replies are blackholed, then send junk +/// UDP for a few seconds while the real rx loop runs. Throughout the burst, +/// read the off-loop `show_transports` view between two live samples, and +/// watch for the tick's entity snapshot publishes. +async fn tick_progress(poisoned: usize) -> TickProgress { + let ms = 300u64; + let (mut node, tx, udp_addr) = node_with_udp_and_tcp(ms).await; + let handle = node.control_read_handle(); + let live_tcp = match tcp(&node) { + TransportHandle::Tcp(t) => t.stats().clone(), + _ => unreachable!(), + }; + let live_udp = match node.transports.get(&TransportId::new(UDP_ID)) { + Some(TransportHandle::Udp(t)) => t.stats().clone(), + _ => unreachable!(), + }; + let bh = Blackhole::silent(); + let poison: Vec = (0..poisoned) + .map(|i| { + let data = craft_msg1(&node, &Identity::generate(), 0x300 + i as u32); + ReceivedPacket::new(TransportId::new(TCP_ID), bh.transport_addr(), data) + }) + .collect(); + let peer = tokio::net::UdpSocket::bind("127.0.0.1:0").await.unwrap(); + + let measure = async { + // The interval's first tick fires at once and publishes a snapshot. + tokio::time::sleep(Duration::from_millis(100)).await; + for p in poison { + tx.send(p).await.unwrap(); + } + // UDP keeps arriving. Junk frames are enough: the transport counts + // them before the rx loop ever sees them. Fourteen replies that each + // dialed for 300 ms would hold the loop longer than the whole burst. + let t0 = Instant::now(); + let mut sent = 0u64; + let mut checks = 0; + let mut off = Vec::new(); + // Holding the last publish seen keeps its allocation alive, so a + // later publish cannot reuse the address and pass for the same one. + let mut last = std::sync::Arc::clone(&*handle.entities()); + let mut last_at = Duration::ZERO; + let mut publishes = 0; + let mut max_gap = Duration::ZERO; + while t0.elapsed() < Duration::from_millis(3600) { + peer.send_to(b"junk-frame", udp_addr).await.unwrap(); + sent += 1; + let before = live_udp.snapshot().packets_recv; + let view = snapshot_stat(&handle, UDP_ID, "packets_recv"); + let after = live_udp.snapshot().packets_recv; + let now = t0.elapsed(); + // A zero count says nothing about whether the view is live. + if before > 0 { + checks += 1; + if view < before || view > after { + off.push((now.as_millis(), before, view, after)); + } + } + let current = std::sync::Arc::clone(&*handle.entities()); + if !std::sync::Arc::ptr_eq(¤t, &last) { + publishes += 1; + max_gap = max_gap.max(now - last_at); + last = current; + last_at = now; + } + tokio::time::sleep(Duration::from_millis(50)).await; + } + max_gap = max_gap.max(t0.elapsed() - last_at); + TickProgress { + sent, + checks, + off, + publishes, + max_gap, + snapshot_timeouts: snapshot_stat(&handle, TCP_ID, "connect_timeouts"), + live_timeouts: live_tcp.snapshot().connect_timeouts, + } + }; + + let progress = tokio::select! { + r = node.run_rx_loop() => panic!("rx loop exited: {r:?}"), + m = measure => m, + }; + stop_all(&mut node).await; + progress +} + +/// While dead TCP replies are queued, the rx loop's tick keeps running and +/// publishing, and the off-loop `show_transports` view tracks the live +/// counters throughout: it reads them at request time rather than from the +/// tick's copy, so it would stay current even if the tick were held. +#[tokio::test] +async fn tick_runs_and_snapshot_tracks_live_counters_under_dead_tcp_replies() { + for poisoned in [0usize, 14] { + let p = tick_progress(poisoned).await; + println!("tick {poisoned} dead TCP replies queued: {p:?}"); + assert!( + p.checks >= 20, + "only {} off-loop reads made from {} UDP frames; the burst did not exercise the view", + p.checks, + p.sent + ); + assert!( + p.off.is_empty(), + "with {poisoned} dead replies queued the off-loop view did not track the live UDP \ + packets_recv in {} of {} reads, first and last (ms, live before, view, live after) \ + {:?} {:?}", + p.off.len(), + p.checks, + p.off.first(), + p.off.last() + ); + assert!( + p.max_gap < SNAPSHOT_LAG, + "with {poisoned} dead replies queued the tick was held: {} publishes, longest gap \ + {:?} (bound {SNAPSHOT_LAG:?})", + p.publishes, + p.max_gap + ); + assert_eq!(p.live_timeouts, 0, "a reply dialed and timed out"); + assert_eq!(p.snapshot_timeouts, p.live_timeouts); + } +} + +/// Through the real accept and receive tasks: a client that sends a +/// msg1 and closes before the node answers draws no connect attempt. With +/// the client still connected, the msg2 goes back on its connection. +/// +/// Over loopback a SYN to the closed client port is answered with a reset, +/// so a dialing reply fails fast with a refusal here rather than stalling; +/// this checks the trigger, and the counters are what show a dial. +#[tokio::test] +async fn msg1_then_close_over_real_tcp_makes_no_connect_attempt() { + // Control: the client stays connected. + let (mut node, _tx, _) = node_with_udp_and_tcp(CONNECT_TIMEOUT_MS).await; + let (mut client, packet) = msg1_over_real_tcp(&mut node).await; + let r = timed_process(&mut node, packet).await; + let answered = client_gets_msg2(&mut client).await; + println!("open-close control client connected: {r:?}, msg2 received {answered}"); + assert_no_dial("open-close control", &r); + assert!(answered, "control: the connected client got no msg2"); + stop_all(&mut node).await; + + let (mut node, _tx, _) = node_with_udp_and_tcp(CONNECT_TIMEOUT_MS).await; + let (client, packet) = msg1_over_real_tcp(&mut node).await; + drop(client); + wait_pool_gone(&node, &packet.remote_addr).await; + let pool_outbound = tcp_stats(&node).pool_outbound; + let r = timed_process(&mut node, packet).await; + println!("open-close client closed first: {r:?}"); + assert_no_dial("msg1 then close", &r); + assert_eq!( + tcp_stats(&node).pool_outbound, + pool_outbound, + "a new outbound pool entry appeared" + ); + assert_eq!(node.peer_count(), 0); + stop_all(&mut node).await; +} + +/// The handshake and link sends the rx loop awaits, other than those +/// covered above, that may reach a TCP link which has gone away. +#[derive(Clone, Copy, Debug)] +enum ReplySite { + /// A second msg1 from the address of a pending inbound handshake: the + /// stored msg2 is resent before any crypto. + DuplicateMsg1, + /// A same-epoch msg1 from an established peer whose session is too young + /// to rekey: the stored msg2 is resent on the established link. + ResendMsg2, + /// A resend of the rekey msg1 we already answered: the held answer is + /// resent on the established link. + ResendRekeyMsg2, + /// The tick's resend of a rekey msg1 to an inbound peer. + RekeyMsg1Resend, + /// The executor's send of the msg1 armed by an outbound dial. + StoredMsg1, + /// An encrypted link message to a peer this node dialed. + LinkMessage, + /// An encrypted link message to a peer that dialed this node. + LinkMessageInbound, +} + +impl ReplySite { + /// Whether the site, finding no connection, starts a background + /// connect: only toward an address this node dialed. + fn connects(self) -> bool { + matches!(self, ReplySite::StoredMsg1 | ReplySite::LinkMessage) + } +} + +/// Bring `row`'s site within one call of firing against a live connection +/// at `bh`, and return the node, the far end, and that call. +async fn arm_site(row: ReplySite, bh: &Blackhole) -> (Node, std::net::TcpStream, Trigger) { + let tcp_id = TransportId::new(TCP_ID); + let link = bh.transport_addr(); + match row { + ReplySite::DuplicateMsg1 => { + let (mut node, _tx, _) = node_with_udp_and_tcp(CONNECT_TIMEOUT_MS).await; + let far_end = prime_link(&node, bh).await; + let link_id = node.allocate_link_id(); + node.links.insert( + link_id, + Link::new( + link_id, + tcp_id, + link.clone(), + LinkDirection::Inbound, + Duration::from_millis(100), + ), + ); + node.addr_to_link.insert((tcp_id, link.clone()), link_id); + node.seed_handshake_machine( + HandshakeSeed::inbound(link_id, 1000) + .with_transport_id(tcp_id) + .with_source_addr(link.clone()), + ) + .unwrap(); + let mut stored = vec![0u8; 69]; + stored[0] = PHASE_MSG2; + stored[2..4].copy_from_slice(&65u16.to_le_bytes()); + node.peer_machines + .get_mut(&link_id) + .unwrap() + .set_conn_handshake_msg2(stored); + let data = craft_msg1(&node, &Identity::generate(), 0x21); + let packet = ReceivedPacket::new(tcp_id, link, data); + (node, far_end, Trigger::Packet(packet)) + } + ReplySite::ResendMsg2 => { + let (node, sender, _, far_end) = peer_on_tcp(bh).await; + let data = craft_msg1(&node, &sender, 0x22); + let packet = ReceivedPacket::new(tcp_id, elsewhere(), data); + (node, far_end, Trigger::Packet(packet)) + } + ReplySite::ResendRekeyMsg2 => { + let (mut node, sender, sender_addr, mut far_end) = peer_on_tcp(bh).await; + node.get_peer_mut(&sender_addr) + .unwrap() + .test_backdate_session_established(Duration::from_secs(31)); + let data = craft_msg1(&node, &sender, 0x23); + node.process_packet(ReceivedPacket::new(tcp_id, elsewhere(), data.clone())) + .await; + assert!( + node.get_peer(&sender_addr) + .is_some_and(|p| p.pending_new_session().is_some()), + "the first rekey msg1 armed a pending session" + ); + assert!( + read_frame(&mut far_end).is_some(), + "the rekey msg2 went out on the connection" + ); + let packet = ReceivedPacket::new(tcp_id, elsewhere(), data); + (node, far_end, Trigger::Packet(packet)) + } + ReplySite::RekeyMsg1Resend => { + let (mut node, _sender, sender_addr, mut far_end) = peer_on_tcp(bh).await; + age_past_rekey(&mut node, &sender_addr); + node.check_rekey().await; + assert!( + node.get_peer(&sender_addr) + .is_some_and(|p| p.rekey_in_progress()), + "the rekey cycle started" + ); + assert!( + read_frame(&mut far_end).is_some_and(|f| is_msg1(&f)), + "the rekey msg1 went out on the connection" + ); + (node, far_end, Trigger::RekeyResend) + } + ReplySite::StoredMsg1 => { + let (mut node, _tx, _) = node_with_udp_and_tcp(CONNECT_TIMEOUT_MS).await; + let far_end = prime_link(&node, bh).await; + let now_ms = Node::now_ms(); + let (link_id, _) = dial_leg(&mut node, &link, now_ms, now_ms + 1000); + (node, far_end, Trigger::StoredMsg1(link_id, link)) + } + ReplySite::LinkMessage => { + let (mut node, _sender, sender_addr, far_end) = peer_on_tcp(bh).await; + make_link_outbound(&mut node, &sender_addr); + (node, far_end, Trigger::LinkMessage(sender_addr)) + } + ReplySite::LinkMessageInbound => { + let (node, _sender, sender_addr, far_end) = peer_on_tcp(bh).await; + (node, far_end, Trigger::LinkMessage(sender_addr)) + } + } +} + +/// Fire `row`'s site with its established connection closed (or, with +/// `dead` false, still open). Returns the measurement, whether the far end +/// received the send, and the transport's connection state for the far +/// end's address afterwards. +async fn fire_site(row: ReplySite, dead: bool) -> (Reply, bool, ConnectionState) { + let mut bh = Blackhole::open(false); + let (mut node, far_end, trigger) = arm_site(row, &bh).await; + let mut far_end = if dead { + kill_link(&node, &mut bh, far_end).await; + None + } else { + Some(far_end) + }; + let r = timed_fire(&mut node, trigger).await; + let delivered = far_end.as_mut().and_then(read_frame).is_some(); + let state = tcp(&node).connection_state(&bh.transport_addr()); + stop_all(&mut node).await; + (r, delivered, state) +} + +/// Every send the rx loop awaits on a TCP link that has gone away returns +/// at once without a connect attempt, and with the link alive the send is +/// delivered. Only a send toward an address this node dialed leaves a +/// background connect behind. +#[tokio::test] +async fn every_rx_loop_handshake_send_to_dead_tcp_link_is_bounded() { + // Every row runs before any assertion, so one red names all the sites + // that dial rather than only the first. + let mut found = Vec::new(); + for row in [ + ReplySite::DuplicateMsg1, + ReplySite::ResendMsg2, + ReplySite::ResendRekeyMsg2, + ReplySite::RekeyMsg1Resend, + ReplySite::StoredMsg1, + ReplySite::LinkMessage, + ReplySite::LinkMessageInbound, + ] { + let (r, delivered, _) = fire_site(row, false).await; + println!("{row:?} control link alive: {r:?}, delivered {delivered}"); + found.extend(dial_findings(&format!("{row:?} control"), &r)); + if !delivered { + found.push(format!("{row:?} control: the send was not delivered")); + } + + let (r, _, state) = fire_site(row, true).await; + println!("{row:?} dead link closed: {r:?}, afterwards {state:?}"); + found.extend(dial_findings(&format!("{row:?} to a closed link"), &r)); + let expected = if row.connects() { + ConnectionState::Connecting + } else { + ConnectionState::None + }; + if state != expected { + found.push(format!( + "{row:?} to a closed link: connection state {state:?}, expected {expected:?}" + )); + } + } + assert!(found.is_empty(), "{}", found.join("\n")); +} + +/// A rekey msg1 copy that arrives over UDP from an address unrelated to the +/// peer is answered on the peer's established TCP link, never at its source. +/// With that link's connection gone it is not answered at all: a +/// connectionless source address is whatever the sender wrote. +#[tokio::test] +async fn a_rekey_msg1_copy_over_udp_is_answered_on_the_established_link_not_its_source() { + for dead in [false, true] { + let mut bh = Blackhole::open(false); + let (mut node, sender, sender_addr, far_end) = peer_on_tcp(&bh).await; + let mut far_end = if dead { + kill_link(&node, &mut bh, far_end).await; + None + } else { + Some(far_end) + }; + node.get_peer_mut(&sender_addr) + .unwrap() + .test_backdate_session_established(Duration::from_secs(31)); + + let source = tokio::net::UdpSocket::bind("127.0.0.1:0").await.unwrap(); + let from = TransportAddr::from_string(&source.local_addr().unwrap().to_string()); + let data = craft_msg1(&node, &sender, 0x31); + let r = timed_process( + &mut node, + ReceivedPacket::new(TransportId::new(UDP_ID), from, data), + ) + .await; + let mut buf = [0u8; 2048]; + let at_source = timeout(Duration::from_millis(300), source.recv_from(&mut buf)) + .await + .is_ok(); + let on_link = far_end + .as_mut() + .and_then(read_frame) + .is_some_and(|f| CommonPrefix::parse(&f).is_some_and(|p| p.phase == PHASE_MSG2)); + let pending = node + .get_peer(&sender_addr) + .is_some_and(|p| p.pending_new_session().is_some()); + stop_all(&mut node).await; + println!( + "udp copy link dead {dead}: {r:?}, msg2 on link {on_link}, at source {at_source}, pending {pending}" + ); + + assert_no_dial("rekey msg1 copy over UDP", &r); + assert!(!at_source, "a msg2 was sent to the copy's UDP source"); + if dead { + assert!(!pending, "an unanswered rekey msg1 stores no session"); + } else { + assert!(on_link, "the msg2 did not go out on the established link"); + assert!(pending, "the answered rekey stores its session"); + } + } +} + +/// Run one send toward an outbound TCP peer whose current address an +/// authenticated frame has moved away from the address the link was dialed +/// at: the tick's rekey msg1 (`rekey`) or a link message. The connection at +/// the moved address is open, or (with `dead`) closed with the address no +/// longer answering. Returns the measurement, whether the send arrived at +/// the moved address, and the connection state there afterwards. +async fn moved_send(rekey: bool, dead: bool) -> (Reply, bool, ConnectionState) { + let bh = Blackhole::open(false); + let (mut node, _sender, sender_addr, _dialed_end) = peer_on_tcp(&bh).await; + make_link_outbound(&mut node, &sender_addr); + let mut moved = Blackhole::open(false); + let moved_end = prime_link(&node, &moved).await; + node.get_peer_mut(&sender_addr) + .unwrap() + .set_current_addr(TransportId::new(TCP_ID), moved.transport_addr()); + let mut moved_end = if dead { + kill_link(&node, &mut moved, moved_end).await; + None + } else { + Some(moved_end) + }; + let trigger = if rekey { + age_past_rekey(&mut node, &sender_addr); + Trigger::RekeyCheck + } else { + Trigger::LinkMessage(sender_addr) + }; + let r = timed_fire(&mut node, trigger).await; + let delivered = moved_end.as_mut().and_then(read_frame).is_some(); + let state = tcp(&node).connection_state(&moved.transport_addr()); + stop_all(&mut node).await; + (r, delivered, state) +} + +/// A peer this node dialed, whose current address has moved, is sent to at +/// the moved address. With the connection there gone the send fails at once +/// and starts no connect toward it: only the address the link was dialed at +/// is known to have a listener, and the moved one may be an ephemeral port. +#[tokio::test] +async fn send_to_moved_outbound_peer_does_not_connect_to_its_moved_address() { + for rekey in [false, true] { + let what = if rekey { "rekey msg1" } else { "link message" }; + let (r, delivered, _) = moved_send(rekey, false).await; + println!("moved peer {what} control connection open: {r:?}, delivered {delivered}"); + assert_no_dial(&format!("moved peer {what} control"), &r); + assert!( + delivered, + "control: the {what} did not go to the moved address" + ); + + let (r, _, state) = moved_send(rekey, true).await; + println!("moved peer {what} connection closed: {r:?}, afterwards {state:?}"); + assert_no_dial(&format!("moved peer {what} to a closed connection"), &r); + assert_eq!( + state, + ConnectionState::None, + "the {what} started a connect toward the peer's moved address" + ); + } +} + +/// A second TCP transport on the node, as a node with two TCP listeners has. +const TCP2_ID: u32 = 3; + +/// Add a second, started TCP transport to `node`. Its frames go to a channel +/// of their own, which the caller keeps alive. +async fn add_second_tcp(node: &mut Node) -> PacketRx { + let (tx, rx) = packet_channel(64); + let cfg = TcpConfig { + bind_addr: Some("127.0.0.1:0".to_string()), + mtu: Some(1400), + connect_timeout_ms: Some(CONNECT_TIMEOUT_MS), + ..Default::default() + }; + let mut t = TcpTransport::new(TransportId::new(TCP2_ID), None, cfg, tx); + t.start_async().await.unwrap(); + node.transports + .insert(TransportId::new(TCP2_ID), TransportHandle::Tcp(t)); + rx +} + +/// A real TCP client connected to the listener of transport `tid`, and its +/// address as that transport's connection pool holds it. +async fn client_on(node: &Node, tid: TransportId) -> (tokio::net::TcpStream, TransportAddr) { + let transport = node.transports.get(&tid).expect("no such transport"); + let listen = transport.local_addr().expect("TCP listener bound"); + let client = tokio::net::TcpStream::connect(listen).await.unwrap(); + let from = TransportAddr::from_string(&client.local_addr().unwrap().to_string()); + let start = Instant::now(); + while transport.connection_state(&from) != ConnectionState::Connected { + assert!( + start.elapsed() < Duration::from_secs(3), + "the client's connection never entered the pool" + ); + tokio::time::sleep(Duration::from_millis(10)).await; + } + (client, from) +} + +/// A same-epoch rekey msg1 from a TCP peer whose established connection has +/// gone is answered on the connection it arrived on when that connection is +/// on the established link's transport. Arriving on another TCP transport it +/// is not answered: the new session's index would be registered under a +/// transport the peer's frames are not looked up on, and that the +/// retirement paths do not remove it from. +#[tokio::test] +async fn a_rekey_msg1_is_answered_on_its_connection_only_on_the_established_transport() { + for other in [false, true] { + let mut bh = Blackhole::open(false); + let (mut node, sender, sender_addr, far_end) = peer_on_tcp(&bh).await; + kill_link(&node, &mut bh, far_end).await; + node.get_peer_mut(&sender_addr) + .unwrap() + .test_backdate_session_established(Duration::from_secs(31)); + let (arrival, _rx) = if other { + ( + TransportId::new(TCP2_ID), + Some(add_second_tcp(&mut node).await), + ) + } else { + (TransportId::new(TCP_ID), None) + }; + + let (mut client, from) = client_on(&node, arrival).await; + let data = craft_msg1(&node, &sender, 0x41); + let r = timed_process(&mut node, ReceivedPacket::new(arrival, from, data)).await; + let answered = client_gets_msg2(&mut client).await; + let pending = node + .get_peer(&sender_addr) + .is_some_and(|p| p.pending_new_session().is_some()); + let indexed = node.peers_by_index.keys().any(|(t, _)| *t == arrival); + stop_all(&mut node).await; + println!( + "redial other transport {other}: {r:?}, answered {answered}, pending {pending}, indexed there {indexed}" + ); + + assert_no_dial("rekey msg1 on a new connection", &r); + if other { + assert!(!answered, "a msg2 went out on another transport"); + assert!(!pending, "an unanswered rekey msg1 stores no session"); + assert!(!indexed, "an index was registered on another transport"); + } else { + assert!(answered, "the msg1's own connection got no msg2"); + assert!(pending, "the answered rekey stores its session"); + assert!(indexed, "the new index is registered on the transport"); + } + } +} + +/// `may_dial` allows a connect only toward the address an outbound link was +/// dialed at, on that link's transport: never for an inbound link, an +/// address the link has since moved to, another transport, or an unknown +/// link. A plain test, with no runtime or sockets. +#[test] +fn may_dial_allows_only_an_outbound_link_s_dial_address_on_its_transport() { + let mut node = make_node(); + let tcp = TransportId::new(1); + let dialed = TransportAddr::from_string("192.0.2.1:443"); + let moved = TransportAddr::from_string("192.0.2.1:50123"); + let (out, inb) = (LinkId::new(1), LinkId::new(2)); + for (id, dir) in [ + (out, LinkDirection::Outbound), + (inb, LinkDirection::Inbound), + ] { + let link = Link::new(id, tcp, dialed.clone(), dir, Duration::from_millis(100)); + node.links.insert(id, link); + } + + assert!(node.may_dial(out, tcp, &dialed), "outbound, dial address"); + assert!(!node.may_dial(out, tcp, &moved), "outbound, moved address"); + assert!( + !node.may_dial(out, TransportId::new(2), &dialed), + "outbound, other transport" + ); + assert!(!node.may_dial(inb, tcp, &dialed), "inbound link"); + assert!(!node.may_dial(LinkId::new(3), tcp, &dialed), "unknown link"); +} diff --git a/src/node/tests/session.rs b/src/node/tests/session.rs index 8bb70718..6334bb4c 100644 --- a/src/node/tests/session.rs +++ b/src/node/tests/session.rs @@ -3087,7 +3087,7 @@ async fn test_tun_outbound_pending_queue_flush() { // ============================================================================ /// Helper: complete a Noise IK handshake and return the initiator's NoiseSession. -fn make_noise_session( +pub(super) fn make_noise_session( our_identity: &Identity, remote_identity: &Identity, ) -> crate::noise::NoiseSession { diff --git a/src/node/tests/tcp.rs b/src/node/tests/tcp.rs index 25a37a3d..590b9510 100644 --- a/src/node/tests/tcp.rs +++ b/src/node/tests/tcp.rs @@ -546,3 +546,157 @@ async fn test_api_disconnect_closes_the_tcp_connection() { cleanup_nodes(&mut nodes).await; } + +/// A peer that redials over TCP after its connection closed, at the same +/// epoch, has its rekey answered on the new connection and completes it, +/// without waiting for the link-dead reaper to remove the stale peering. +/// +/// node 0 dialed node 1. node 0's connection closes, and node 1 still holds +/// the peering at node 0's old source port, where nothing answers. node 0's +/// rekey finds no connection, starts a background connect, and sends its +/// msg1 on the new connection a tick later. node 1 answers on that +/// connection, node 0 completes the rekey and cuts over, and its first frame +/// on the new session moves node 1's link to the new connection. +#[tokio::test] +async fn same_epoch_tcp_redial_completes_its_rekey_without_waiting_for_the_reaper() { + use crate::proto::link::LinkMessageType; + use std::time::Instant; + + const REKEY_AFTER_SECS: u64 = 60; + let age = Duration::from_secs(REKEY_AFTER_SECS + crate::node::REKEY_JITTER_SECS as u64 + 1); + let mut cfg0 = Config::new(); + cfg0.node.rekey.after_secs = REKEY_AFTER_SECS; + cfg0.node.rekey.after_messages = u64::MAX; + let mut cfg1 = Config::new(); + cfg1.node.rekey.after_secs = u64::MAX; + cfg1.node.rekey.after_messages = u64::MAX; + let mut nodes = vec![ + make_test_node_tcp_with(cfg0).await, + make_test_node_tcp_with(cfg1).await, + ]; + initiate_handshake(&mut nodes, 0, 1).await; + drain_all_packets(&mut nodes, false).await; + let addr0 = *nodes[0].node.node_addr(); + let addr1 = *nodes[1].node.node_addr(); + assert!(nodes[0].node.get_peer(&addr1).is_some(), "node 0 peers"); + let old_addr = nodes[1] + .node + .get_peer(&addr0) + .expect("node 1 peers") + .current_addr() + .cloned() + .unwrap(); + nodes[0] + .node + .get_peer_mut(&addr1) + .unwrap() + .test_backdate_session_established(age); + nodes[1] + .node + .get_peer_mut(&addr0) + .unwrap() + .test_backdate_session_established(age); + + // node 0's connection closes; node 1's receive task drops its end. + let node1_listen = nodes[1].addr.clone(); + let t0 = nodes[0].transport_id; + let t1 = nodes[1].transport_id; + nodes[0] + .node + .transports + .get(&t0) + .unwrap() + .close_connection(&node1_listen) + .await; + let start = Instant::now(); + while nodes[1] + .node + .transports + .get(&t1) + .unwrap() + .connection_state(&old_addr) + != ConnectionState::None + { + assert!( + start.elapsed() < Duration::from_secs(3), + "node 1 never dropped the closed connection" + ); + tokio::time::sleep(Duration::from_millis(10)).await; + } + + // node 0's rekey: the tick retries until the msg1 goes out. + let start = Instant::now(); + while !nodes[0].node.get_peer(&addr1).unwrap().rekey_in_progress() { + assert!( + start.elapsed() < Duration::from_secs(3), + "node 0's rekey msg1 never went out" + ); + nodes[0].node.check_rekey().await; + tokio::time::sleep(Duration::from_millis(50)).await; + } + + // The msg1 reaches node 1 on the new connection, the msg2 node 0. + for _ in 0..50 { + tokio::time::sleep(Duration::from_millis(20)).await; + process_available_packets(&mut nodes).await; + if nodes[0] + .node + .get_peer(&addr1) + .unwrap() + .pending_new_session() + .is_some() + { + break; + } + } + let pending_idx = nodes[1] + .node + .get_peer(&addr0) + .unwrap() + .pending_our_index() + .expect("node 1 must answer the redialed rekey and hold its new session"); + assert!( + nodes[0] + .node + .get_peer(&addr1) + .unwrap() + .pending_new_session() + .is_some(), + "node 0 must complete its rekey on the answer" + ); + + // node 0 cuts over; its first frame on the new session promotes node 1's + // pending and moves node 1's link to the new connection. + nodes[0].node.check_rekey().await; + nodes[0] + .node + .send_encrypted_link_message(&addr1, &[LinkMessageType::Heartbeat.to_byte()]) + .await + .expect("node 0 sends on the new connection"); + for _ in 0..50 { + tokio::time::sleep(Duration::from_millis(20)).await; + process_available_packets(&mut nodes).await; + if nodes[1].node.get_peer(&addr0).unwrap().our_index() == Some(pending_idx) { + break; + } + } + let peer = nodes[1].node.get_peer(&addr0).unwrap(); + assert_eq!( + peer.our_index(), + Some(pending_idx), + "node 1 must promote the session it answered with" + ); + assert_ne!( + peer.current_addr(), + Some(&old_addr), + "node 1's link must move to the new connection" + ); + let took = start.elapsed(); + println!("redial rekey completed {took:?} after node 0's first rekey tick"); + assert!( + took < Duration::from_secs(5), + "the rekey took {took:?}; the link-dead reaper is 30 s" + ); + + cleanup_nodes(&mut nodes).await; +} diff --git a/src/testutil.rs b/src/testutil.rs index f55e42e8..442890d7 100644 --- a/src/testutil.rs +++ b/src/testutil.rs @@ -78,3 +78,100 @@ pub(crate) fn capture_logs_scoped() -> (LogCapture, tracing::subscriber::Default let guard = tracing::subscriber::set_default(subscriber); (capture, guard) } + +/// Poll `f` every 10ms until it holds or `limit` elapses. +/// +/// Uses tokio's clock, so a test running with paused time advances through +/// the waits instead of sleeping. +pub(crate) async fn wait_until bool>(mut f: F, limit: std::time::Duration) -> bool { + let deadline = tokio::time::Instant::now() + limit; + loop { + if f() { + return true; + } + if tokio::time::Instant::now() >= deadline { + return false; + } + tokio::time::sleep(std::time::Duration::from_millis(10)).await; + } +} + +/// A local TCP address whose SYNs go unanswered once filled. +/// +/// A listener with a backlog of one whose accept queue is filled: Linux, +/// macOS and the BSDs drop further SYNs to a listener whose accept queue is +/// full, so a connect to it times out rather than completing or being +/// refused. How many connects the queue takes before it is full differs by +/// kernel (one on Linux, more on macOS), so filling stops at the first +/// connect that times out. The listener and the fillers must be kept alive +/// for as long as that is relied on. +pub(crate) struct Blackhole { + pub(crate) listener: socket2::Socket, + fillers: Vec, + pub(crate) addr: std::net::SocketAddr, +} + +impl Blackhole { + /// A listener with backlog 1. Not 0: macOS reads a backlog of 0 as the + /// system default (about 128), so its queue would not fill. + /// + /// When `fill` is false the accept queue is left empty, so at least one + /// connect completes; [`Blackhole::fill`] fills it later. + pub(crate) fn open(fill: bool) -> Self { + use socket2::{Domain, Socket, Type}; + let listener = Socket::new(Domain::IPV4, Type::STREAM, None).unwrap(); + let bind: std::net::SocketAddr = "127.0.0.1:0".parse().unwrap(); + listener.bind(&bind.into()).unwrap(); + listener.listen(1).unwrap(); + let addr = listener.local_addr().unwrap().as_socket().unwrap(); + let mut bh = Self { + listener, + fillers: Vec::new(), + addr, + }; + if fill { + bh.fill(); + } + bh + } + + /// A listener whose SYNs already go unanswered. + pub(crate) fn silent() -> Self { + Self::open(true) + } + + /// Fill the listener's accept queue, stopping at the first connect that + /// times out, which shows a further connect now times out instead of + /// completing or being refused. + pub(crate) fn fill(&mut self) { + const MAX_FILLERS: usize = 64; + for _ in 0..=MAX_FILLERS { + let probe = std::net::TcpStream::connect_timeout( + &self.addr, + std::time::Duration::from_millis(200), + ); + match probe { + Ok(filler) => self.fillers.push(filler), + Err(e) if e.kind() == std::io::ErrorKind::TimedOut => return, + Err(e) => panic!("blackhole is not silent: probe connect returned {e:?}"), + } + } + panic!("blackhole is not silent: {MAX_FILLERS} connects completed"); + } + + /// Accept every filler still queued on the listener, so the address + /// answers again: the next connect to it, or the next retransmitted SYN + /// of one already waiting, completes. Returns the accepted far ends, + /// which the caller keeps alive while it relies on that. + pub(crate) fn drain(&mut self) -> Vec { + self.fillers + .iter() + .map(|_| std::net::TcpStream::from(self.listener.accept().unwrap().0)) + .collect() + } + + /// The address in the transport form. + pub(crate) fn transport_addr(&self) -> crate::transport::TransportAddr { + crate::transport::TransportAddr::from_string(&self.addr.to_string()) + } +} diff --git a/src/transport/mod.rs b/src/transport/mod.rs index 79f55fe8..2d8b85ac 100644 --- a/src/transport/mod.rs +++ b/src/transport/mod.rs @@ -142,6 +142,12 @@ pub enum TransportError { #[error("connection refused")] ConnectionRefused, + /// No connection to the address exists, and the send did not open one. + /// The connection a reply was meant for has gone; the remote's next + /// attempt arrives on a new one. + #[error("not connected")] + NotConnected, + #[error("transport not supported: {0}")] NotSupported(String), @@ -652,6 +658,46 @@ pub struct TransportCongestion { pub recv_drops: Option, } +// ============================================================================ +// Background Connects +// ============================================================================ + +/// What a background connect task yields: the connected stream and the MTU +/// to use on it. +pub(crate) type ConnectOutcome = Result<(tokio::net::TcpStream, u16), TransportError>; + +/// Take the background connect for `addr` out of `connecting` if its task +/// has finished, and return what it produced. +/// +/// Returns `None`, leaving the map untouched, when there is no attempt for +/// the address or it is still running. +pub(crate) fn take_finished_connect( + connecting: &mut std::collections::HashMap, + addr: &TransportAddr, +) -> Option +where + E: AsMut>, +{ + use futures::FutureExt; + + let task = connecting.get_mut(addr)?.as_mut(); + if !task.is_finished() { + return None; + } + // Polling a JoinHandle spends the caller's cooperative budget, and with + // none left it reads pending even though the task has finished. Poll it + // unconstrained, and remove the entry only once its output is in hand, + // so a connected stream is never dropped unread. + let joined = tokio::task::unconstrained(task).now_or_never()?; + connecting.remove(addr); + match joined { + Ok(outcome) => Some(outcome), + Err(e) => Some(Err(TransportError::LinkFailed(format!( + "connect task failed: {e}" + )))), + } +} + // ============================================================================ // Transport Handle // ============================================================================ @@ -729,6 +775,36 @@ impl TransportHandle { } } + /// Send data only over a connection that already exists; never dial. + /// + /// On TCP, Tor and Nym, a background connect that has finished is taken + /// into the pool and used; otherwise the call fails at once with + /// [`TransportError::NotConnected`] and opens nothing. Connectionless + /// transports have no connection to look up and send as + /// [`send`](Self::send) does. BLE's send never waits on a connect and is + /// used as is. + /// + /// Use this from anything the rx loop awaits: a dial there holds every + /// other frame for up to the transport's connect timeout. + pub async fn send_existing( + &self, + addr: &TransportAddr, + data: &[u8], + ) -> Result { + match self { + TransportHandle::Udp(t) => t.send_async(addr, data).await, + #[cfg(any(target_os = "linux", target_os = "macos"))] + TransportHandle::Ethernet(t) => t.send_async(addr, data).await, + TransportHandle::Tcp(t) => t.send_existing(addr, data).await, + TransportHandle::Tor(t) => t.send_existing(addr, data).await, + TransportHandle::Nym(t) => t.send_existing(addr, data).await, + #[cfg(ble_available)] + TransportHandle::Ble(t) => t.send_async(addr, data).await, + #[cfg(test)] + TransportHandle::Loopback(t) => t.send_async(addr, data).await, + } + } + /// Get the transport ID. pub fn transport_id(&self) -> TransportId { match self { @@ -1042,29 +1118,92 @@ impl TransportHandle { /// /// Returns a snapshot of counters for the specific transport type. pub fn transport_stats(&self) -> serde_json::Value { + self.live_stats().to_json() + } + + /// The transport's shared counters, for reading live off the rx loop. + /// + /// The counters are atomics the transport updates from its own tasks and + /// threads, so a holder sees them move without anything republishing + /// them. + pub(crate) fn live_stats(&self) -> LiveStats { match self { - TransportHandle::Udp(t) => { - serde_json::to_value(t.stats().snapshot()).unwrap_or_default() - } + TransportHandle::Udp(t) => LiveStats::Udp(t.stats().clone()), #[cfg(any(target_os = "linux", target_os = "macos"))] - TransportHandle::Ethernet(t) => { - serde_json::to_value(t.stats().snapshot()).unwrap_or_default() - } - TransportHandle::Tcp(t) => { - serde_json::to_value(t.stats().snapshot()).unwrap_or_default() - } - TransportHandle::Tor(t) => { - serde_json::to_value(t.stats().snapshot()).unwrap_or_default() - } - TransportHandle::Nym(t) => { - serde_json::to_value(t.stats().snapshot()).unwrap_or_default() - } + TransportHandle::Ethernet(t) => LiveStats::Ethernet(t.stats().clone()), + TransportHandle::Tcp(t) => LiveStats::Tcp(t.stats().clone()), + TransportHandle::Tor(t) => LiveStats::Tor(t.stats().clone()), + TransportHandle::Nym(t) => LiveStats::Nym(t.stats().clone()), #[cfg(ble_available)] - TransportHandle::Ble(t) => { - serde_json::to_value(t.stats().snapshot()).unwrap_or_default() - } + TransportHandle::Ble(t) => LiveStats::Ble(t.stats().clone()), #[cfg(test)] - TransportHandle::Loopback(_) => serde_json::json!({}), + TransportHandle::Loopback(_) => LiveStats::Empty, + } + } +} + +/// A transport's shared counters, held by reference rather than copied. +/// +/// Cloning shares the counters. `show_transports` holds one per transport in +/// its published row and reads it at request time, so the counters it shows +/// are current even when nothing has republished the row. +#[derive(Clone)] +pub(crate) enum LiveStats { + /// UDP transport counters. + Udp(std::sync::Arc), + /// Ethernet transport counters. + #[cfg(any(target_os = "linux", target_os = "macos"))] + Ethernet(std::sync::Arc), + /// TCP transport counters. + Tcp(std::sync::Arc), + /// Tor transport counters. + Tor(std::sync::Arc), + /// Nym transport counters. + Nym(std::sync::Arc), + /// BLE transport counters. + #[cfg(ble_available)] + Ble(std::sync::Arc), + /// No counters (the test loopback transport). + #[cfg(test)] + Empty, +} + +impl LiveStats { + /// Read the counters now, as the JSON `show_transports` reports under + /// `stats`. + pub(crate) fn to_json(&self) -> serde_json::Value { + match self { + LiveStats::Udp(s) => serde_json::to_value(s.snapshot()).unwrap_or_default(), + #[cfg(any(target_os = "linux", target_os = "macos"))] + LiveStats::Ethernet(s) => serde_json::to_value(s.snapshot()).unwrap_or_default(), + LiveStats::Tcp(s) => serde_json::to_value(s.snapshot()).unwrap_or_default(), + LiveStats::Tor(s) => serde_json::to_value(s.snapshot()).unwrap_or_default(), + LiveStats::Nym(s) => serde_json::to_value(s.snapshot()).unwrap_or_default(), + #[cfg(ble_available)] + LiveStats::Ble(s) => serde_json::to_value(s.snapshot()).unwrap_or_default(), + #[cfg(test)] + LiveStats::Empty => serde_json::json!({}), + } + } +} + +/// Two values are equal when they share the same counters, not when the +/// counters happen to read the same. +impl PartialEq for LiveStats { + fn eq(&self, other: &Self) -> bool { + use std::sync::Arc; + match (self, other) { + (LiveStats::Udp(a), LiveStats::Udp(b)) => Arc::ptr_eq(a, b), + #[cfg(any(target_os = "linux", target_os = "macos"))] + (LiveStats::Ethernet(a), LiveStats::Ethernet(b)) => Arc::ptr_eq(a, b), + (LiveStats::Tcp(a), LiveStats::Tcp(b)) => Arc::ptr_eq(a, b), + (LiveStats::Tor(a), LiveStats::Tor(b)) => Arc::ptr_eq(a, b), + (LiveStats::Nym(a), LiveStats::Nym(b)) => Arc::ptr_eq(a, b), + #[cfg(ble_available)] + (LiveStats::Ble(a), LiveStats::Ble(b)) => Arc::ptr_eq(a, b), + #[cfg(test)] + (LiveStats::Empty, LiveStats::Empty) => true, + _ => false, } } } @@ -1109,6 +1248,47 @@ pub(crate) async fn resolve_socket_addrs( mod tests { use super::*; + /// A connecting-pool entry holding only its connect task. + struct TaskEntry(tokio::task::JoinHandle); + + impl AsMut> for TaskEntry { + /// The background connect task. + fn as_mut(&mut self) -> &mut tokio::task::JoinHandle { + &mut self.0 + } + } + + /// A finished connect is handed back even when the calling task has + /// spent its cooperative budget, which makes a plain poll of the task + /// read pending. Losing it there would close a connected stream unseen. + #[tokio::test] + async fn take_finished_connect_returns_the_outcome_when_the_caller_budget_is_spent() { + let addr = TransportAddr::from_socket_addr("192.0.2.1:2121".parse().unwrap()); + let task = tokio::spawn(async { Err(TransportError::ConnectionRefused) }); + while !task.is_finished() { + tokio::task::yield_now().await; + } + let mut connecting = std::collections::HashMap::from([(addr.clone(), TaskEntry(task))]); + + for _ in 0..10_000 { + if !tokio::task::coop::has_budget_remaining() { + break; + } + tokio::task::consume_budget().await; + } + assert!( + !tokio::task::coop::has_budget_remaining(), + "the test runtime must budget this task, or the case is not exercised" + ); + + let outcome = take_finished_connect(&mut connecting, &addr); + assert!( + matches!(outcome, Some(Err(TransportError::ConnectionRefused))), + "finished connect not returned: {outcome:?}" + ); + assert!(connecting.is_empty()); + } + #[test] fn test_transport_id() { let id = TransportId::new(42); diff --git a/src/transport/nym/mod.rs b/src/transport/nym/mod.rs index 11381df6..01f6b7ff 100644 --- a/src/transport/nym/mod.rs +++ b/src/transport/nym/mod.rs @@ -21,7 +21,7 @@ use super::{ use crate::config::NymConfig; use crate::transport::socks5::{ ConnectingEntry, ConnectingPool, DialError, ProxiedConnection, ProxiedPool, Socks5Auth, - Socks5Dialer, SocksTarget, poll_connecting, proxied_receive_loop, + Socks5Dialer, SocksTarget, existing_writer, poll_connecting, proxied_receive_loop, }; use stats::NymStats; @@ -245,16 +245,7 @@ impl NymTransport { if !self.state.is_operational() { return Err(TransportError::NotStarted); } - - // Pre-send MTU check - let mtu = self.config.mtu() as usize; - if data.len() > mtu { - self.stats.record_mtu_exceeded(); - return Err(TransportError::MtuExceeded { - packet_size: data.len(), - mtu: self.config.mtu(), - }); - } + self.check_mtu(data)?; // Get or create connection let writer = { @@ -270,7 +261,53 @@ impl NymTransport { } }; - // Write packet + self.write_packet(addr, writer, data).await + } + + /// Send a packet only over a connection that already exists. + /// + /// Uses the pooled connection for `addr`, or one a finished background + /// connect has produced, which it moves into the pool. Never dials: with + /// neither, it fails at once with [`TransportError::NotConnected`]. + pub async fn send_existing( + &self, + addr: &TransportAddr, + data: &[u8], + ) -> Result { + if !self.state.is_operational() { + return Err(TransportError::NotStarted); + } + self.check_mtu(data)?; + let writer = existing_writer(&self.pool, &self.connecting, addr, |stream, mtu| { + let conn = self.outbound_connection(addr, stream, mtu); + self.record_promoted(addr); + conn + }) + .await + .ok_or(TransportError::NotConnected)?; + self.write_packet(addr, writer, data).await + } + + /// Reject a packet larger than the transport MTU before writing it. + fn check_mtu(&self, data: &[u8]) -> Result<(), TransportError> { + if data.len() > self.config.mtu() as usize { + self.stats.record_mtu_exceeded(); + return Err(TransportError::MtuExceeded { + packet_size: data.len(), + mtu: self.config.mtu(), + }); + } + Ok(()) + } + + /// Write one packet to `writer`, the connection to `addr`, and drop the + /// connection from the pool if the write fails. + async fn write_packet( + &self, + addr: &TransportAddr, + writer: Arc>, + data: &[u8], + ) -> Result { let mut w = writer.lock().await; match w.write_all(data).await { Ok(()) => { @@ -421,6 +458,7 @@ impl NymTransport { let transport_id = self.transport_id; let remote_addr = addr.clone(); let config = self.config.clone(); + let stats = self.stats.clone(); debug!( transport_id = %transport_id, @@ -455,7 +493,9 @@ impl NymTransport { ); stream } + // Counted as connect() counts them. Err(DialError::Socks(e)) => { + stats.record_socks5_error(); warn!( transport_id = %transport_id, remote_addr = %remote_addr, @@ -466,6 +506,7 @@ impl NymTransport { return Err(TransportError::ConnectionRefused); } Err(DialError::Timeout) => { + stats.record_connect_timeout(); warn!( transport_id = %transport_id, remote_addr = %remote_addr, @@ -499,6 +540,29 @@ impl NymTransport { /// Promote a completed background connection to the established pool. fn promote_connection(&self, addr: &TransportAddr, stream: TcpStream, mtu: u16) { + let conn = self.outbound_connection(addr, stream, mtu); + + if let Ok(mut pool) = self.pool.try_lock() { + pool.insert(addr.clone(), conn); + self.record_promoted(addr); + } else { + conn.recv_task.abort(); + warn!( + transport_id = %self.transport_id, + remote_addr = %addr, + "Failed to promote Nym connection (pool locked)" + ); + } + } + + /// Build the pool entry for a finished background connect: split the + /// stream and spawn its receive loop. + fn outbound_connection( + &self, + addr: &TransportAddr, + stream: TcpStream, + mtu: u16, + ) -> ProxiedConnection<()> { let (read_half, write_half) = stream.into_split(); let writer = Arc::new(Mutex::new(write_half)); @@ -521,32 +585,25 @@ impl NymTransport { .await; }); - let conn = ProxiedConnection { + ProxiedConnection { writer, recv_task, mtu, established_at: Instant::now(), meta: (), - }; - - if let Ok(mut pool) = self.pool.try_lock() { - pool.insert(addr.clone(), conn); - self.stats.record_connection_established(); - debug!( - transport_id = %self.transport_id, - remote_addr = %addr, - "Nym connection established (background connect)" - ); - } else { - conn.recv_task.abort(); - warn!( - transport_id = %self.transport_id, - remote_addr = %addr, - "Failed to promote Nym connection (pool locked)" - ); } } + /// Count and log a background connection that has entered the pool. + fn record_promoted(&self, addr: &TransportAddr) { + self.stats.record_connection_established(); + debug!( + transport_id = %self.transport_id, + remote_addr = %addr, + "Nym connection established (background connect)" + ); + } + /// Close a specific connection asynchronously. pub async fn close_connection_async(&self, addr: &TransportAddr) { let mut pool = self.pool.lock().await; @@ -711,6 +768,7 @@ fn validate_host_port(addr: &str, field: &str) -> Result<(), TransportError> { #[cfg(test)] mod tests { use super::*; + use crate::testutil::wait_until; use crate::transport::packet_channel; /// Test config: a syntactically valid loopback proxy address, with the @@ -1000,4 +1058,188 @@ mod tests { nym.stop_async().await.unwrap(); dest.stop_async().await.unwrap(); } + + /// A destination TCP transport behind a mock SOCKS5 proxy, and a + /// started Nym transport pointed at the proxy. + async fn nym_behind_mock_proxy() -> ( + NymTransport, + TcpTransport, + crate::transport::PacketRx, + TransportAddr, + ) { + let (dest_tx, dest_rx) = packet_channel(32); + let dest_config = TcpConfig { + bind_addr: Some("127.0.0.1:0".to_string()), + ..Default::default() + }; + let mut dest = TcpTransport::new(TransportId::new(100), None, dest_config, dest_tx); + dest.start_async().await.unwrap(); + let dest_addr = dest.local_addr().unwrap(); + + let mock = MockSocks5Server::new(dest_addr).await.unwrap(); + let proxy_addr = mock.addr(); + let _proxy_handle = mock.spawn(); + + let (tx, _rx) = packet_channel(32); + let config = NymConfig { + socks5_addr: Some(proxy_addr.to_string()), + startup_timeout_secs: Some(5), + connect_timeout_ms: Some(5000), + ..Default::default() + }; + let mut t = NymTransport::new(TransportId::new(200), None, config, tx); + t.start_async().await.unwrap(); + let target = TransportAddr::from_string(&dest_addr.to_string()); + (t, dest, dest_rx, target) + } + + /// With no pooled connection and no connect under way, `send_existing` + /// fails with `NotConnected` and opens nothing. + #[tokio::test] + async fn send_existing_without_connection_fails_fast_and_dials_nothing() { + let (mut t, mut dest, _dest_rx, target) = nym_behind_mock_proxy().await; + + let result = t.send_existing(&target, &build_msg1_frame()).await; + + assert!( + matches!(result, Err(TransportError::NotConnected)), + "expected NotConnected, got {result:?}" + ); + assert!( + t.connecting.lock().await.is_empty(), + "a connect was started" + ); + assert_eq!(t.stats().snapshot().connections_established, 0); + tokio::time::sleep(Duration::from_millis(100)).await; + assert_eq!( + dest.stats().snapshot().connections_accepted, + 0, + "the destination saw a connection" + ); + + t.stop_async().await.unwrap(); + dest.stop_async().await.unwrap(); + } + + /// A background connect that has finished is moved into the pool and + /// carries the send, with no second connection opened. + #[tokio::test] + async fn send_existing_promotes_a_finished_background_connect_and_sends_on_it() { + let (mut t, mut dest, mut dest_rx, target) = nym_behind_mock_proxy().await; + + t.connect_async(&target).await.unwrap(); + let mut waited = 0; + while !t + .connecting + .try_lock() + .is_ok_and(|c| c.get(&target).is_some_and(|e| e.task.is_finished())) + { + assert!(waited < 150, "background connect never finished"); + tokio::time::sleep(Duration::from_millis(20)).await; + waited += 1; + } + let frame = build_msg1_frame(); + t.send_existing(&target, &frame).await.unwrap(); + + let received = tokio::time::timeout(Duration::from_secs(5), dest_rx.recv()) + .await + .expect("timeout waiting for packet") + .expect("channel closed"); + assert_eq!(received.data, frame); + assert!( + t.connecting.lock().await.is_empty(), + "the finished connect was left in the connecting map" + ); + assert_eq!(t.stats().snapshot().connections_established, 1); + assert_eq!( + dest.stats().snapshot().connections_accepted, + 1, + "the send used the background connection, not a new one" + ); + + t.stop_async().await.unwrap(); + dest.stop_async().await.unwrap(); + } + + /// Wait until the background connect to `target` has finished, leaving + /// it in the connecting map. + async fn wait_background_finished(t: &NymTransport, target: &TransportAddr) { + let finished = wait_until( + || { + t.connecting + .try_lock() + .is_ok_and(|c| c.get(target).is_some_and(|e| e.task.is_finished())) + }, + Duration::from_secs(3), + ) + .await; + assert!(finished, "background connect to {target} never finished"); + } + + /// A background connect through a proxy that accepts the TCP connection + /// but never answers the SOCKS5 greeting times out, and is counted in + /// `connect_timeouts` as an inline one is. + #[tokio::test] + async fn background_connect_timeout_is_counted() { + // Bound and listening, never accepted: the kernel completes the TCP + // handshake and nothing ever replies. + let silent = std::net::TcpListener::bind("127.0.0.1:0").unwrap(); + let (tx, _rx) = packet_channel(32); + let config = NymConfig { + socks5_addr: Some(silent.local_addr().unwrap().to_string()), + startup_timeout_secs: Some(5), + connect_timeout_ms: Some(200), + ..Default::default() + }; + let mut t = NymTransport::new(TransportId::new(200), None, config, tx); + t.start_async().await.unwrap(); + let target = TransportAddr::from_string("127.0.0.1:9"); + + t.connect_async(&target).await.unwrap(); + wait_background_finished(&t, &target).await; + + let stats = t.stats().snapshot(); + assert_eq!(stats.connect_timeouts, 1, "the timeout was not counted"); + assert_eq!(stats.socks5_errors, 0); + let result = t.send_existing(&target, &build_msg1_frame()).await; + assert!(matches!(result, Err(TransportError::NotConnected))); + assert_eq!( + t.stats().snapshot().connect_timeouts, + 1, + "taking the result counted the timeout again" + ); + + t.stop_async().await.unwrap(); + } + + /// A background connect the proxy answers with a SOCKS5 failure is + /// counted in `socks5_errors` as an inline one is. + #[tokio::test] + async fn background_connect_socks5_error_is_counted() { + let dummy_target: std::net::SocketAddr = "127.0.0.1:1".parse().unwrap(); + let mock = MockSocks5Server::with_reply_code(dummy_target, 0x01) + .await + .unwrap(); + let proxy_addr = mock.addr(); + let _proxy_handle = mock.spawn(); + let (tx, _rx) = packet_channel(32); + let config = NymConfig { + socks5_addr: Some(proxy_addr.to_string()), + startup_timeout_secs: Some(5), + connect_timeout_ms: Some(2000), + ..Default::default() + }; + let mut t = NymTransport::new(TransportId::new(200), None, config, tx); + t.start_async().await.unwrap(); + let target = TransportAddr::from_string("127.0.0.1:9"); + + t.connect_async(&target).await.unwrap(); + wait_background_finished(&t, &target).await; + + let stats = t.stats().snapshot(); + assert_eq!(stats.socks5_errors, 1, "the SOCKS5 error was not counted"); + assert_eq!(stats.connect_timeouts, 0); + + t.stop_async().await.unwrap(); + } } diff --git a/src/transport/socks5/mod.rs b/src/transport/socks5/mod.rs index eb628830..731eb220 100644 --- a/src/transport/socks5/mod.rs +++ b/src/transport/socks5/mod.rs @@ -11,8 +11,8 @@ mod stats; pub use dialer::{DialError, Socks5Auth, Socks5Dialer, SocksTarget}; pub(crate) use pool::{ - ConnectingEntry, ConnectingPool, ProxiedConnection, ProxiedPool, ProxiedStats, poll_connecting, - proxied_receive_loop, + ConnectingEntry, ConnectingPool, ProxiedConnection, ProxiedPool, ProxiedStats, existing_writer, + poll_connecting, proxied_receive_loop, }; pub(crate) use stats::ProxiedStatsBase; diff --git a/src/transport/socks5/pool.rs b/src/transport/socks5/pool.rs index 4ed24f28..f86c7a90 100644 --- a/src/transport/socks5/pool.rs +++ b/src/transport/socks5/pool.rs @@ -21,6 +21,7 @@ use crate::transport::framing::read_fmp_packet; use crate::transport::tcp::InboundDeadline; use crate::transport::{ ConnectionState, PacketTx, ReceivedPacket, TransportAddr, TransportError, TransportId, + take_finished_connect, }; /// State for a single pooled connection to a peer. @@ -54,6 +55,13 @@ pub(crate) struct ConnectingEntry { pub task: JoinHandle>, } +impl AsMut>> for ConnectingEntry { + /// The background connect task. + fn as_mut(&mut self) -> &mut JoinHandle> { + &mut self.task + } +} + /// Map of addresses with background connection attempts in progress. pub(crate) type ConnectingPool = Arc>>; @@ -114,6 +122,42 @@ pub(crate) fn poll_connecting( } } +/// The writer for an established connection to `addr`, promoting a +/// background connect that has finished since it was started. +/// +/// `promote` builds the pool entry for a finished connect and does the +/// transport's own accounting; it runs with the pool lock held, so the +/// connection cannot be inserted twice. A finished connect that failed is +/// dropped, so the next `connect_async` starts a new attempt. Never dials. +pub(crate) async fn existing_writer( + pool: &ProxiedPool, + connecting: &ConnectingPool, + addr: &TransportAddr, + promote: impl FnOnce(TcpStream, u16) -> ProxiedConnection, +) -> Option>> { + let mut pool = pool.lock().await; + if let Some(conn) = pool.get(addr) { + return Some(conn.writer.clone()); + } + let finished = take_finished_connect(&mut *connecting.lock().await, addr)?; + match finished { + Ok((stream, mtu)) => { + let conn = promote(stream, mtu); + let writer = conn.writer.clone(); + pool.insert(addr.clone(), conn); + Some(writer) + } + Err(e) => { + debug!( + remote_addr = %addr, + error = %e, + "Background SOCKS5 connect failed, nothing to send on" + ); + None + } + } +} + /// Minimal stats surface the shared receive loop needs. /// /// The per-transport stats structs implement this by delegating to their diff --git a/src/transport/tcp/mod.rs b/src/transport/tcp/mod.rs index 268ca729..f36c3b9b 100644 --- a/src/transport/tcp/mod.rs +++ b/src/transport/tcp/mod.rs @@ -25,11 +25,11 @@ mod pool; pub mod stats; -use super::resolve_socket_addrs; use super::{ ConnectionState, DiscoveredPeer, PacketTx, ReceivedPacket, Transport, TransportAddr, TransportError, TransportId, TransportState, TransportType, }; +use super::{resolve_socket_addrs, take_finished_connect}; use crate::config::TcpConfig; use crate::transport::framing::read_fmp_packet; use pool::{ @@ -335,19 +335,7 @@ impl TcpTransport { if !self.state.is_operational() { return Err(TransportError::NotStarted); } - - // Pre-send MTU check: reject oversize packets before writing them - // to the TCP stream. Without this, the receiver's FMP stream reader - // would see payload_len > max and close the connection, causing a - // disruptive reset-reconnect cycle. - let mtu = self.config.mtu() as usize; - if data.len() > mtu { - self.stats.record_mtu_exceeded(); - return Err(TransportError::MtuExceeded { - packet_size: data.len(), - mtu: self.config.mtu(), - }); - } + self.check_mtu(data)?; // Get or create connection let writer = { @@ -363,6 +351,86 @@ impl TcpTransport { } }; + self.write_packet(addr, writer, data).await + } + + /// Send a packet only over a connection that already exists. + /// + /// Uses the pooled connection for `addr`, or one a finished background + /// connect has produced, which it moves into the pool. Never dials: with + /// neither, it fails at once with [`TransportError::NotConnected`]. + pub async fn send_existing( + &self, + addr: &TransportAddr, + data: &[u8], + ) -> Result { + if !self.state.is_operational() { + return Err(TransportError::NotStarted); + } + self.check_mtu(data)?; + let writer = self + .existing_writer(addr) + .await + .ok_or(TransportError::NotConnected)?; + self.write_packet(addr, writer, data).await + } + + /// The writer for an established connection to `addr`, promoting a + /// background connect that has finished since it was started. + /// + /// Holds the pool lock across the promotion, so the connection cannot be + /// inserted twice. A finished connect that failed is dropped, so the next + /// `connect_async` starts a new attempt. + async fn existing_writer(&self, addr: &TransportAddr) -> Option>> { + let mut pool = self.pool.lock().await; + if let Some(conn) = key_for_remote(&pool, addr).and_then(|key| pool.get(&key)) { + return Some(conn.writer.clone()); + } + let finished = take_finished_connect(&mut *self.connecting.lock().await, addr)?; + match finished { + Ok((stream, mss_mtu)) => { + let conn = self.outbound_connection(addr, stream, mss_mtu); + let writer = conn.writer.clone(); + pool.insert(PoolKey::outbound(addr.clone()), conn); + self.record_promoted(addr, mss_mtu); + Some(writer) + } + Err(e) => { + debug!( + transport_id = %self.transport_id, + remote_addr = %addr, + error = %e, + "Background TCP connect failed, nothing to send on" + ); + None + } + } + } + + /// Reject a packet larger than the transport MTU before writing it. + /// + /// Without this, the receiver's FMP stream reader would see + /// payload_len > max and close the connection, causing a disruptive + /// reset-reconnect cycle. + fn check_mtu(&self, data: &[u8]) -> Result<(), TransportError> { + if data.len() > self.config.mtu() as usize { + self.stats.record_mtu_exceeded(); + return Err(TransportError::MtuExceeded { + packet_size: data.len(), + mtu: self.config.mtu(), + }); + } + Ok(()) + } + + /// Write one packet to `writer`, the connection to `addr`, and drop the + /// connection from the pool if the write fails. + async fn write_packet( + &self, + addr: &TransportAddr, + writer: Arc>, + data: &[u8], + ) -> Result { // Write packet directly (no framing transformation needed) let mut w = writer.lock().await; match w.write_all(data).await { @@ -544,6 +612,7 @@ impl TcpTransport { let config = self.config.clone(); let transport_id = self.transport_id; let remote_addr = addr.clone(); + let stats = self.stats.clone(); debug!( transport_id = %transport_id, @@ -557,11 +626,18 @@ impl TcpTransport { let socket_addrs: Vec<_> = resolve_socket_addrs(&remote_addr).await?.collect(); // A refusal is logged with its OS error by connect_to_any_addr. + // Failures are counted here, where they happen, as connect() + // counts them; whoever later takes the result does not. let connected = connect_to_any_addr(transport_id, &remote_addr, &socket_addrs, timeout_ms).await; let stream = match connected { Ok(stream) => stream, + Err(error @ TransportError::ConnectionRefused) => { + stats.record_connect_refused(); + return Err(error); + } Err(error @ TransportError::Timeout) => { + stats.record_connect_timeout(); debug!( transport_id = %transport_id, remote_addr = %remote_addr, @@ -659,6 +735,32 @@ impl TcpTransport { /// Splits the stream, spawns a receive loop, and inserts into the pool. /// Called from `connection_state_sync()` when a background task completes. fn promote_connection(&self, addr: &TransportAddr, stream: TcpStream, mss_mtu: u16) { + let conn = self.outbound_connection(addr, stream, mss_mtu); + + // Use try_lock since we're in a sync context and the pool + // should be available (connection_state_sync already checked it) + if let Ok(mut pool) = self.pool.try_lock() { + pool.insert(PoolKey::outbound(addr.clone()), conn); + self.record_promoted(addr, mss_mtu); + } else { + // Pool locked — abort the recv task, connection will be retried + conn.recv_task.abort(); + warn!( + transport_id = %self.transport_id, + remote_addr = %addr, + "Failed to promote connection (pool locked)" + ); + } + } + + /// Build the pool entry for a finished background connect: split the + /// stream and spawn its receive loop. + fn outbound_connection( + &self, + addr: &TransportAddr, + stream: TcpStream, + mss_mtu: u16, + ) -> TcpConnection { let (read_half, write_half) = stream.into_split(); let writer = Arc::new(Mutex::new(write_half)); @@ -666,8 +768,7 @@ impl TcpTransport { let packet_tx = self.packet_tx.clone(); let pool = self.pool.clone(); let recv_stats = self.stats.clone(); - let key = PoolKey::outbound(addr.clone()); - let recv_key = key.clone(); + let recv_key = PoolKey::outbound(addr.clone()); let recv_task = tokio::spawn(async move { tcp_receive_loop( @@ -687,36 +788,26 @@ impl TcpTransport { .await; }); - let conn = TcpConnection { + TcpConnection { writer, recv_task, mtu: mss_mtu, established_at: Instant::now(), direction: Direction::Outbound, - }; - - // Use try_lock since we're in a sync context and the pool - // should be available (connection_state_sync already checked it) - if let Ok(mut pool) = self.pool.try_lock() { - pool.insert(key, conn); - self.stats.record_connection_established(); - self.stats.record_pool_outbound_added(); - debug!( - transport_id = %self.transport_id, - remote_addr = %addr, - mtu = mss_mtu, - "TCP connection established (background connect)" - ); - } else { - // Pool locked — abort the recv task, connection will be retried - conn.recv_task.abort(); - warn!( - transport_id = %self.transport_id, - remote_addr = %addr, - "Failed to promote connection (pool locked)" - ); } } + + /// Count and log a background connection that has entered the pool. + fn record_promoted(&self, addr: &TransportAddr, mss_mtu: u16) { + self.stats.record_connection_established(); + self.stats.record_pool_outbound_added(); + debug!( + transport_id = %self.transport_id, + remote_addr = %addr, + mtu = mss_mtu, + "TCP connection established (background connect)" + ); + } } impl Transport for TcpTransport { @@ -1298,24 +1389,11 @@ fn read_mss_mtu(stream: &std::net::TcpStream, default_mtu: u16) -> u16 { #[cfg(test)] mod tests { use super::*; + use crate::testutil::{Blackhole, wait_until}; use crate::transport::framing::{build_established_frame, build_msg1_frame}; use crate::transport::packet_channel; use tokio::time::{Duration, timeout}; - /// Poll `f` every 10ms until it holds or `limit` elapses. - async fn wait_until bool>(mut f: F, limit: Duration) -> bool { - let deadline = Instant::now() + limit; - loop { - if f() { - return true; - } - if Instant::now() >= deadline { - return false; - } - tokio::time::sleep(Duration::from_millis(10)).await; - } - } - fn capped_config(max_inbound: usize) -> TcpConfig { TcpConfig { bind_addr: Some("127.0.0.1:0".to_string()), @@ -2756,4 +2834,247 @@ mod tests { transport.stop_async().await.unwrap(); } + + /// A minimal msg1-phase frame the receive loop accepts. + fn msg1_frame() -> Vec { + let mut frame = vec![0xAA; 114]; + frame[0] = 0x01; + frame[1] = 0x00; + frame[2..4].copy_from_slice(&110u16.to_le_bytes()); + frame + } + + /// A minimal msg2-phase frame the receive loop accepts. + fn msg2_frame() -> Vec { + let mut frame = vec![0xBB; 69]; + frame[0] = 0x02; + frame[1] = 0x00; + frame[2..4].copy_from_slice(&65u16.to_le_bytes()); + frame + } + + /// Wait until the background connect to `remote` has finished, leaving + /// it unpromoted in the connecting map. + async fn wait_connect_finished(t: &TcpTransport, remote: &TransportAddr) { + let finished = wait_until( + || { + t.connecting + .try_lock() + .is_ok_and(|c| c.get(remote).is_some_and(|e| e.task.is_finished())) + }, + Duration::from_secs(3), + ) + .await; + assert!(finished, "background connect to {remote} never finished"); + } + + /// With no pooled connection and no connect under way, `send_existing` + /// fails with `NotConnected` and opens nothing. + #[tokio::test] + async fn send_existing_without_connection_fails_fast_and_dials_nothing() { + let (tx1, _rx1) = packet_channel(100); + let (tx2, _rx2) = packet_channel(100); + let mut t1 = TcpTransport::new(TransportId::new(1), None, make_outbound_config(), tx1); + let mut t2 = TcpTransport::new(TransportId::new(2), None, make_config(), tx2); + t1.start_async().await.unwrap(); + t2.start_async().await.unwrap(); + // Reachable, so a send that dialed would succeed. + let remote = TransportAddr::from_string(&t2.local_addr().unwrap().to_string()); + + let result = t1.send_existing(&remote, &msg1_frame()).await; + + assert!( + matches!(result, Err(TransportError::NotConnected)), + "expected NotConnected, got {result:?}" + ); + assert!( + t1.connecting.lock().await.is_empty(), + "a connect was started" + ); + assert_eq!(t1.connection_state_sync(&remote), ConnectionState::None); + assert_eq!(t1.stats().snapshot().connections_established, 0); + tokio::time::sleep(Duration::from_millis(100)).await; + assert_eq!( + t2.stats().snapshot().connections_accepted, + 0, + "the remote saw a connection" + ); + + t1.stop_async().await.unwrap(); + t2.stop_async().await.unwrap(); + } + + /// A background connect that has finished is moved into the pool and + /// carries the send, with no second connection opened. + #[tokio::test] + async fn send_existing_promotes_a_finished_background_connect_and_sends_on_it() { + let (tx1, _rx1) = packet_channel(100); + let (tx2, mut rx2) = packet_channel(100); + let mut t1 = TcpTransport::new(TransportId::new(1), None, make_outbound_config(), tx1); + let mut t2 = TcpTransport::new(TransportId::new(2), None, make_config(), tx2); + t1.start_async().await.unwrap(); + t2.start_async().await.unwrap(); + let remote = TransportAddr::from_string(&t2.local_addr().unwrap().to_string()); + + t1.connect_async(&remote).await.unwrap(); + wait_connect_finished(&t1, &remote).await; + let frame = msg1_frame(); + let sent = t1.send_existing(&remote, &frame).await.unwrap(); + assert_eq!(sent, frame.len()); + + let packet = timeout(Duration::from_secs(2), rx2.recv()) + .await + .expect("timeout") + .expect("channel closed"); + assert_eq!(packet.data, frame); + assert!( + t1.connecting.lock().await.is_empty(), + "the finished connect was left in the connecting map" + ); + let stats = t1.stats().snapshot(); + assert_eq!(stats.connections_established, 1); + assert_eq!(stats.pool_outbound, 1); + assert_eq!( + t2.stats().snapshot().connections_accepted, + 1, + "the send used the background connection, not a new one" + ); + + t1.stop_async().await.unwrap(); + t2.stop_async().await.unwrap(); + } + + /// A background connect that failed is dropped from the connecting map, + /// the send fails with `NotConnected`, and `connect_async` can start again. + #[tokio::test] + async fn send_existing_after_a_failed_background_connect_drops_it_so_a_new_one_can_start() { + let (tx, _rx) = packet_channel(100); + let mut t = TcpTransport::new(TransportId::new(1), None, make_outbound_config(), tx); + t.start_async().await.unwrap(); + // A port nothing listens on: the connect is refused. + let closed = std::net::TcpListener::bind("127.0.0.1:0").unwrap(); + let remote = TransportAddr::from_string(&closed.local_addr().unwrap().to_string()); + drop(closed); + + t.connect_async(&remote).await.unwrap(); + wait_connect_finished(&t, &remote).await; + let result = t.send_existing(&remote, &msg1_frame()).await; + + assert!( + matches!(result, Err(TransportError::NotConnected)), + "expected NotConnected, got {result:?}" + ); + assert!( + t.connecting.lock().await.get(&remote).is_none(), + "the failed connect was left in the connecting map" + ); + t.connect_async(&remote).await.unwrap(); + assert!( + t.connecting.lock().await.get(&remote).is_some(), + "connect_async did not start a new attempt" + ); + + t.stop_async().await.unwrap(); + } + + /// A reply to a peer that connected in goes back on that inbound + /// connection. + #[tokio::test] + async fn send_existing_replies_on_a_live_inbound_connection() { + let (tx1, mut rx1) = packet_channel(100); + let (tx2, mut rx2) = packet_channel(100); + let mut t1 = TcpTransport::new(TransportId::new(1), None, make_outbound_config(), tx1); + let mut t2 = TcpTransport::new(TransportId::new(2), None, make_config(), tx2); + t1.start_async().await.unwrap(); + t2.start_async().await.unwrap(); + let remote = TransportAddr::from_string(&t2.local_addr().unwrap().to_string()); + + t1.send_async(&remote, &msg1_frame()).await.unwrap(); + let inbound = timeout(Duration::from_secs(2), rx2.recv()) + .await + .expect("timeout") + .expect("channel closed"); + // The frame is only forwarded once the accept loop has pooled the + // connection, so a reply to its address finds it. + let reply = msg2_frame(); + t2.send_existing(&inbound.remote_addr, &reply) + .await + .unwrap(); + + let packet = timeout(Duration::from_secs(2), rx1.recv()) + .await + .expect("timeout") + .expect("channel closed"); + assert_eq!(packet.data, reply); + assert_eq!( + t2.stats().snapshot().connections_established, + 0, + "the reply dialed" + ); + + t1.stop_async().await.unwrap(); + t2.stop_async().await.unwrap(); + } + + /// A background connect that times out is counted in `connect_timeouts`, + /// as an inline one is. + #[tokio::test] + async fn background_connect_timeout_is_counted() { + let bh = Blackhole::silent(); + let (tx, _rx) = packet_channel(100); + let config = TcpConfig { + connect_timeout_ms: Some(200), + ..make_outbound_config() + }; + let mut t = TcpTransport::new(TransportId::new(1), None, config, tx); + t.start_async().await.unwrap(); + let remote = bh.transport_addr(); + + t.connect_async(&remote).await.unwrap(); + wait_connect_finished(&t, &remote).await; + + let stats = t.stats().snapshot(); + assert_eq!(stats.connect_timeouts, 1, "the timeout was not counted"); + assert_eq!(stats.connect_refused, 0); + assert_eq!( + t.connection_state_sync(&remote), + ConnectionState::Failed("transport timeout".into()) + ); + assert_eq!( + t.stats().snapshot().connect_timeouts, + 1, + "taking the result counted the timeout again" + ); + + t.stop_async().await.unwrap(); + } + + /// A background connect that is refused is counted in `connect_refused`, + /// as an inline one is. + #[tokio::test] + async fn background_connect_refusal_is_counted() { + let (tx, _rx) = packet_channel(100); + let mut t = TcpTransport::new(TransportId::new(1), None, make_outbound_config(), tx); + t.start_async().await.unwrap(); + // A port nothing listens on: the connect is refused. + let closed = std::net::TcpListener::bind("127.0.0.1:0").unwrap(); + let remote = TransportAddr::from_string(&closed.local_addr().unwrap().to_string()); + drop(closed); + + t.connect_async(&remote).await.unwrap(); + wait_connect_finished(&t, &remote).await; + + let stats = t.stats().snapshot(); + assert_eq!(stats.connect_refused, 1, "the refusal was not counted"); + assert_eq!(stats.connect_timeouts, 0); + let result = t.send_existing(&remote, &msg1_frame()).await; + assert!(matches!(result, Err(TransportError::NotConnected))); + assert_eq!( + t.stats().snapshot().connect_refused, + 1, + "taking the result counted the refusal again" + ); + + t.stop_async().await.unwrap(); + } } diff --git a/src/transport/tcp/pool.rs b/src/transport/tcp/pool.rs index 9c3124da..2e76b38d 100644 --- a/src/transport/tcp/pool.rs +++ b/src/transport/tcp/pool.rs @@ -113,5 +113,12 @@ pub(crate) struct ConnectingEntry { pub(crate) task: JoinHandle>, } +impl AsMut>> for ConnectingEntry { + /// The background connect task. + fn as_mut(&mut self) -> &mut JoinHandle> { + &mut self.task + } +} + /// Map of addresses with background connection attempts in progress. pub(crate) type ConnectingPool = Arc>>; diff --git a/src/transport/tcp/stats.rs b/src/transport/tcp/stats.rs index 62340e4f..be8e73d7 100644 --- a/src/transport/tcp/stats.rs +++ b/src/transport/tcp/stats.rs @@ -21,7 +21,14 @@ pub struct TcpStats { pub connections_established: AtomicU64, pub connections_accepted: AtomicU64, pub connections_rejected: AtomicU64, + /// Outbound connects, inline or in the background, that did not complete + /// within `connect_timeout_ms`. pub connect_timeouts: AtomicU64, + /// Outbound connects, inline or in the background, that failed before + /// the timeout. Despite the name this counts every such failure, not + /// only `ECONNREFUSED`: an unreachable host or network, a reset or any + /// other connect error lands here too. The debug log "TCP connect + /// failed" carries the OS error for each one. pub connect_refused: AtomicU64, /// Inbound/outbound connection-pool occupancy. Inbound drives the /// `max_inbound_connections` admission check. @@ -95,7 +102,8 @@ impl TcpStats { self.connect_timeouts.fetch_add(1, Ordering::Relaxed); } - /// Record a connection refused. + /// Record an outbound connect that failed before its timeout, for any + /// reason (see `connect_refused`). pub fn record_connect_refused(&self) { self.connect_refused.fetch_add(1, Ordering::Relaxed); } diff --git a/src/transport/tor/mod.rs b/src/transport/tor/mod.rs index 6730f6b6..7cd094a9 100644 --- a/src/transport/tor/mod.rs +++ b/src/transport/tor/mod.rs @@ -31,7 +31,7 @@ use super::{ use crate::config::TorConfig; use crate::transport::socks5::{ ConnectingEntry, ConnectingPool, DialError, ProxiedConnection, ProxiedPool, Socks5Auth, - Socks5Dialer, SocksTarget, poll_connecting, proxied_receive_loop, + Socks5Dialer, SocksTarget, existing_writer, poll_connecting, proxied_receive_loop, }; use crate::transport::tcp::{INBOUND_FIRST_FRAME_TIMEOUT, INBOUND_IDLE_TIMEOUT, InboundDeadline}; use control::{ControlAuth, TorControlClient, TorMonitoringInfo}; @@ -653,16 +653,7 @@ impl TorTransport { if !self.state.is_operational() { return Err(TransportError::NotStarted); } - - // Pre-send MTU check - let mtu = self.config.mtu() as usize; - if data.len() > mtu { - self.stats.record_mtu_exceeded(); - return Err(TransportError::MtuExceeded { - packet_size: data.len(), - mtu: self.config.mtu(), - }); - } + self.check_mtu(data)?; // Get or create connection let writer = { @@ -678,6 +669,53 @@ impl TorTransport { } }; + self.write_packet(addr, writer, data).await + } + + /// Send a packet only over a connection that already exists. + /// + /// Uses the pooled connection for `addr`, or one a finished background + /// connect has produced, which it moves into the pool. Never dials: with + /// neither, it fails at once with [`TransportError::NotConnected`]. + pub async fn send_existing( + &self, + addr: &TransportAddr, + data: &[u8], + ) -> Result { + if !self.state.is_operational() { + return Err(TransportError::NotStarted); + } + self.check_mtu(data)?; + let writer = existing_writer(&self.pool, &self.connecting, addr, |stream, mtu| { + let conn = self.outbound_connection(addr, stream, mtu); + self.record_promoted(addr); + conn + }) + .await + .ok_or(TransportError::NotConnected)?; + self.write_packet(addr, writer, data).await + } + + /// Reject a packet larger than the transport MTU before writing it. + fn check_mtu(&self, data: &[u8]) -> Result<(), TransportError> { + if data.len() > self.config.mtu() as usize { + self.stats.record_mtu_exceeded(); + return Err(TransportError::MtuExceeded { + packet_size: data.len(), + mtu: self.config.mtu(), + }); + } + Ok(()) + } + + /// Write one packet to `writer`, the connection to `addr`, and drop the + /// connection from the pool if the write fails. + async fn write_packet( + &self, + addr: &TransportAddr, + writer: Arc>, + data: &[u8], + ) -> Result { // Write packet directly (no framing transformation needed) let mut w = writer.lock().await; match w.write_all(data).await { @@ -907,6 +945,7 @@ impl TorTransport { return Err(TransportError::ConnectionRefused); } Err(DialError::Timeout) => { + stats.record_connect_timeout(); debug!( transport_id = %transport_id, remote_addr = %remote_addr, @@ -947,6 +986,32 @@ impl TorTransport { /// Splits the stream, spawns a receive loop, and inserts into the pool. /// Called from `connection_state_sync()` when a background task completes. fn promote_connection(&self, addr: &TransportAddr, stream: TcpStream, mtu: u16) { + let conn = self.outbound_connection(addr, stream, mtu); + + // Use try_lock since we're in a sync context and the pool + // should be available (connection_state_sync already checked it) + if let Ok(mut pool) = self.pool.try_lock() { + pool.insert(addr.clone(), conn); + self.record_promoted(addr); + } else { + // Pool locked — abort the recv task, connection will be retried + conn.recv_task.abort(); + warn!( + transport_id = %self.transport_id, + remote_addr = %addr, + "Failed to promote Tor connection (pool locked)" + ); + } + } + + /// Build the pool entry for a finished background connect: split the + /// stream and spawn its receive loop. + fn outbound_connection( + &self, + addr: &TransportAddr, + stream: TcpStream, + mtu: u16, + ) -> ProxiedConnection { let (read_half, write_half) = stream.into_split(); let writer = Arc::new(Mutex::new(write_half)); @@ -974,36 +1039,26 @@ impl TorTransport { .await; }); - let conn = ProxiedConnection { + ProxiedConnection { writer, recv_task, mtu, established_at: Instant::now(), meta: Direction::Outbound, - }; - - // Use try_lock since we're in a sync context and the pool - // should be available (connection_state_sync already checked it) - if let Ok(mut pool) = self.pool.try_lock() { - pool.insert(addr.clone(), conn); - self.stats.record_connection_established(); - self.stats.record_pool_outbound_added(); - debug!( - transport_id = %self.transport_id, - remote_addr = %addr, - "Tor connection established (background connect)" - ); - } else { - // Pool locked — abort the recv task, connection will be retried - conn.recv_task.abort(); - warn!( - transport_id = %self.transport_id, - remote_addr = %addr, - "Failed to promote Tor connection (pool locked)" - ); } } + /// Count and log a background connection that has entered the pool. + fn record_promoted(&self, addr: &TransportAddr) { + self.stats.record_connection_established(); + self.stats.record_pool_outbound_added(); + debug!( + transport_id = %self.transport_id, + remote_addr = %addr, + "Tor connection established (background connect)" + ); + } + /// Close a specific connection asynchronously. pub async fn close_connection_async(&self, addr: &TransportAddr) { let mut pool = self.pool.lock().await; @@ -1319,6 +1374,7 @@ fn validate_host_port(addr: &str, field_name: &str) -> Result<(), TransportError #[cfg(test)] mod tests { use super::*; + use crate::testutil::wait_until; use crate::transport::packet_channel; fn make_config() -> TorConfig { @@ -1977,20 +2033,6 @@ mod tests { // Inbound first-frame deadline (onion listener) // ======================================================================== - /// Poll `f` every 10ms until it holds or `limit` elapses. - async fn wait_until bool>(mut f: F, limit: Duration) -> bool { - let deadline = Instant::now() + limit; - loop { - if f() { - return true; - } - if Instant::now() >= deadline { - return false; - } - tokio::time::sleep(Duration::from_millis(10)).await; - } - } - /// Drives `tor_accept_loop` directly: the only production path to it is /// `start_directory_mode`, which needs a Tor-managed hostname file and a /// running daemon, so it is not reachable from a unit test. @@ -2436,4 +2478,204 @@ mod tests { accept.abort(); drop(sock); } + + /// A destination TCP transport behind a mock SOCKS5 proxy, and a + /// started Tor transport pointed at the proxy. + async fn tor_behind_mock_proxy() -> ( + TorTransport, + TcpTransport, + crate::transport::PacketRx, + TransportAddr, + ) { + let (dest_tx, dest_rx) = packet_channel(32); + let dest_config = TcpConfig { + bind_addr: Some("127.0.0.1:0".to_string()), + ..Default::default() + }; + let mut dest = TcpTransport::new(TransportId::new(100), None, dest_config, dest_tx); + dest.start_async().await.unwrap(); + let dest_addr = dest.local_addr().unwrap(); + + let mock = MockSocks5Server::new(dest_addr).await.unwrap(); + let proxy_addr = mock.addr(); + let _proxy_handle = mock.spawn(); + + let (tx, _rx) = packet_channel(32); + let config = TorConfig { + socks5_addr: Some(proxy_addr.to_string()), + ..Default::default() + }; + let mut t = TorTransport::new(TransportId::new(200), None, config, tx); + t.start_async().await.unwrap(); + let target = TransportAddr::from_string(&dest_addr.to_string()); + (t, dest, dest_rx, target) + } + + /// With no pooled connection and no connect under way, `send_existing` + /// fails with `NotConnected` and opens nothing. + #[tokio::test] + async fn send_existing_without_connection_fails_fast_and_dials_nothing() { + let (mut t, mut dest, _dest_rx, target) = tor_behind_mock_proxy().await; + + let result = t.send_existing(&target, &build_msg1_frame()).await; + + assert!( + matches!(result, Err(TransportError::NotConnected)), + "expected NotConnected, got {result:?}" + ); + assert!( + t.connecting.lock().await.is_empty(), + "a connect was started" + ); + assert_eq!(t.stats().snapshot().connections_established, 0); + tokio::time::sleep(Duration::from_millis(100)).await; + assert_eq!( + dest.stats().snapshot().connections_accepted, + 0, + "the destination saw a connection" + ); + + t.stop_async().await.unwrap(); + dest.stop_async().await.unwrap(); + } + + /// A background connect that has finished is moved into the pool and + /// carries the send, with no second connection opened. + #[tokio::test] + async fn send_existing_promotes_a_finished_background_connect_and_sends_on_it() { + let (mut t, mut dest, mut dest_rx, target) = tor_behind_mock_proxy().await; + + t.connect_async(&target).await.unwrap(); + let mut waited = 0; + while !t + .connecting + .try_lock() + .is_ok_and(|c| c.get(&target).is_some_and(|e| e.task.is_finished())) + { + assert!(waited < 150, "background connect never finished"); + tokio::time::sleep(Duration::from_millis(20)).await; + waited += 1; + } + let frame = build_msg1_frame(); + t.send_existing(&target, &frame).await.unwrap(); + + let received = tokio::time::timeout(Duration::from_secs(5), dest_rx.recv()) + .await + .expect("timeout waiting for packet") + .expect("channel closed"); + assert_eq!(received.data, frame); + assert!( + t.connecting.lock().await.is_empty(), + "the finished connect was left in the connecting map" + ); + assert_eq!(t.stats().snapshot().connections_established, 1); + assert_eq!( + dest.stats().snapshot().connections_accepted, + 1, + "the send used the background connection, not a new one" + ); + + t.stop_async().await.unwrap(); + dest.stop_async().await.unwrap(); + } + + /// When the background connect fails because the SOCKS5 proxy is + /// unreachable, `send_existing` fails with `NotConnected`, drops the + /// failed connect, and `connect_async` can start a new attempt. + #[tokio::test] + async fn send_existing_after_a_failed_background_connect_drops_it_so_a_new_one_can_start() { + // A proxy port nothing listens on: every connect through it fails. + let closed = std::net::TcpListener::bind("127.0.0.1:0").unwrap(); + let proxy_addr = closed.local_addr().unwrap(); + drop(closed); + let (tx, _rx) = packet_channel(32); + let config = TorConfig { + socks5_addr: Some(proxy_addr.to_string()), + ..Default::default() + }; + let mut t = TorTransport::new(TransportId::new(200), None, config, tx); + t.start_async().await.unwrap(); + let target = TransportAddr::from_string("127.0.0.1:9"); + + t.connect_async(&target).await.unwrap(); + let mut waited = 0; + while !t + .connecting + .try_lock() + .is_ok_and(|c| c.get(&target).is_some_and(|e| e.task.is_finished())) + { + assert!(waited < 150, "background connect never finished"); + tokio::time::sleep(Duration::from_millis(20)).await; + waited += 1; + } + let result = t.send_existing(&target, &build_msg1_frame()).await; + + assert!( + matches!(result, Err(TransportError::NotConnected)), + "expected NotConnected, got {result:?}" + ); + assert!( + t.connecting.lock().await.get(&target).is_none(), + "the failed connect was left in the connecting map" + ); + assert!(t.pool.lock().await.is_empty()); + t.connect_async(&target).await.unwrap(); + assert!( + t.connecting.lock().await.get(&target).is_some(), + "connect_async did not start a new attempt" + ); + + t.stop_async().await.unwrap(); + } + + /// Wait until the background connect to `target` has finished, leaving + /// it in the connecting map. + async fn wait_background_finished(t: &TorTransport, target: &TransportAddr) { + let finished = wait_until( + || { + t.connecting + .try_lock() + .is_ok_and(|c| c.get(target).is_some_and(|e| e.task.is_finished())) + }, + Duration::from_secs(3), + ) + .await; + assert!(finished, "background connect to {target} never finished"); + } + + /// A background connect through a proxy that accepts the TCP connection + /// but never answers the SOCKS5 greeting times out, and is counted in + /// `connect_timeouts` as an inline one is. + #[tokio::test] + async fn background_connect_timeout_is_counted() { + // Bound and listening, never accepted: the kernel completes the TCP + // handshake and nothing ever replies. + let silent = std::net::TcpListener::bind("127.0.0.1:0").unwrap(); + let (tx, _rx) = packet_channel(32); + let config = TorConfig { + socks5_addr: Some(silent.local_addr().unwrap().to_string()), + connect_timeout_ms: Some(200), + ..Default::default() + }; + let mut t = TorTransport::new(TransportId::new(200), None, config, tx); + t.start_async().await.unwrap(); + let target = TransportAddr::from_string("127.0.0.1:9"); + + t.connect_async(&target).await.unwrap(); + wait_background_finished(&t, &target).await; + + let stats = t.stats().snapshot(); + assert_eq!(stats.connect_timeouts, 1, "the timeout was not counted"); + assert_eq!(stats.connect_refused, 0); + assert_eq!(stats.socks5_errors, 0); + let result = t.send_existing(&target, &build_msg1_frame()).await; + assert!(matches!(result, Err(TransportError::NotConnected))); + assert_eq!( + t.stats().snapshot().connect_timeouts, + 1, + "taking the result counted the timeout again" + ); + + t.stop_async().await.unwrap(); + } } diff --git a/src/transport/udp/io/connected/drain.rs b/src/transport/udp/io/connected/drain.rs index de276509..04bbfdf8 100644 --- a/src/transport/udp/io/connected/drain.rs +++ b/src/transport/udp/io/connected/drain.rs @@ -12,7 +12,9 @@ //! `recvmsg_x(2)` on Darwin), push each packet into //! the existing `packet_tx` (the same channel that the wildcard listen //! socket feeds), and exit cleanly when the parent signals shutdown -//! via a self-pipe. +//! via a self-pipe. Each datagram is counted in the transport's +//! `UdpStats`, as the wildcard socket counts its own, so the transport's +//! receive counters cover every datagram it receives. //! //! Future: when the full data-plane shard lands, this per-peer thread //! becomes a `epoll_wait` arm inside the shard's event loop instead @@ -20,6 +22,7 @@ //! useful in either shape; only the wakeup mechanism differs. use super::socket::ConnectedPeerSocket; +use crate::transport::udp::UdpStats; use crate::transport::{PacketTx, ReceivedPacket, TransportAddr, TransportId}; use std::io; use std::net::SocketAddr; @@ -53,12 +56,14 @@ impl PeerRecvDrain { /// kernel fd alive while it's running. When this handle drops, /// the stop pipe fires; the thread exits; its `Arc` releases. /// If the parent also releases its `Arc`, the socket's `Drop` - /// closes the kernel fd. + /// closes the kernel fd. `stats` is the owning UDP transport's, so + /// datagrams read here are counted with the rest of its traffic. pub fn spawn( socket: Arc, transport_id: TransportId, peer_addr: SocketAddr, packet_tx: PacketTx, + stats: Arc, ) -> io::Result { // Self-pipe for shutdown signaling. The drain thread polls // (socket_fd | pipe_rx) so a write to pipe_tx wakes it. @@ -76,6 +81,7 @@ impl PeerRecvDrain { transport_id, peer_addr, packet_tx, + stats, pipe_rx, stop_clone, ); @@ -137,6 +143,7 @@ fn drain_loop( transport_id: TransportId, peer_addr: SocketAddr, packet_tx: PacketTx, + stats: Arc, stop_pipe_rx: RawFd, stop: Arc, ) { @@ -231,6 +238,7 @@ fn drain_loop( if len == 0 { continue; } + stats.record_recv(len); // Move the filled buffer out, refill the slot with a // fresh one. Same zero-copy pattern the wildcard listen // socket uses (see `transport/udp/mod.rs::run_receive_loop`). @@ -452,7 +460,8 @@ mod tests { /// End-to-end: open a ConnectedPeerSocket, spawn a drain thread /// on it, send packets at it from a remote, verify they land in - /// the packet_tx mpsc with the correct transport_id + peer_addr. + /// the packet_tx mpsc with the correct transport_id + peer_addr, + /// and that each is counted in the stats the drain was given. #[tokio::test(flavor = "multi_thread", worker_threads = 2)] async fn drain_delivers_packets_to_packet_tx() { // Peer (remote) — sends packets at our connected socket. @@ -499,8 +508,10 @@ mod tests { }; // Spawn the drain. - let _drain = PeerRecvDrain::spawn(socket.clone(), transport_id, peer_addr, tx) - .expect("PeerRecvDrain::spawn"); + let stats = Arc::new(UdpStats::new()); + let _drain = + PeerRecvDrain::spawn(socket.clone(), transport_id, peer_addr, tx, stats.clone()) + .expect("PeerRecvDrain::spawn"); // Send a couple of packets from the peer to our socket. for i in 0u8..5 { @@ -518,6 +529,12 @@ mod tests { assert_eq!(pkt.data.len(), 4); assert_eq!(pkt.data[0], i, "packet {i} payload mismatch"); } + let counted = stats.snapshot(); + assert_eq!( + counted.packets_recv, 5, + "the drain did not count what it delivered" + ); + assert_eq!(counted.bytes_recv, 20); // Drop the drain handle — should stop the thread within one // poll iteration. } diff --git a/src/transport/udp/mod.rs b/src/transport/udp/mod.rs index 9ea1a3f8..b5131ce7 100644 --- a/src/transport/udp/mod.rs +++ b/src/transport/udp/mod.rs @@ -14,7 +14,7 @@ use super::resolve_socket_addr; use crate::config::UdpConfig; use crate::nostr::is_punch_packet; use io::{AsyncUdpSocket, UdpRawSocket}; -use stats::UdpStats; +pub(crate) use stats::UdpStats; use std::collections::HashMap; use std::net::SocketAddr; use std::sync::{Arc, Mutex as StdMutex}; diff --git a/src/transport/udp/stats.rs b/src/transport/udp/stats.rs index a0bb79c6..3c2afdc1 100644 --- a/src/transport/udp/stats.rs +++ b/src/transport/udp/stats.rs @@ -40,6 +40,21 @@ impl UdpStats { self.bytes_sent.fetch_add(bytes as u64, Ordering::Relaxed); } + /// Record `packets` datagrams totalling `bytes` handed to the kernel in + /// one batched send (`sendmmsg(2)` or UDP GSO), counted as that many + /// separate sends. + pub fn record_sends(&self, packets: u64, bytes: u64) { + self.packets_sent.fetch_add(packets, Ordering::Relaxed); + self.bytes_sent.fetch_add(bytes, Ordering::Relaxed); + } + + /// Record `packets` datagrams a batched send did not deliver to the + /// kernel, whether after an error or because the kernel took none of + /// them, counted as that many send errors. + pub fn record_unsent(&self, packets: u64) { + self.send_errors.fetch_add(packets, Ordering::Relaxed); + } + /// Record a successful receive. pub fn record_recv(&self, bytes: usize) { self.packets_recv.fetch_add(1, Ordering::Relaxed); @@ -61,11 +76,14 @@ impl UdpStats { self.mtu_exceeded.fetch_add(1, Ordering::Relaxed); } - /// Update kernel drop count from SO_MEMINFO. + /// Update the kernel drop count. /// - /// Not yet wired up — requires `getsockopt(SO_MEMINFO)` on the raw fd - /// (via socket2 or libc) to read `SK_MEMINFO_DROPS`. Linux-only. - /// Until implemented, this counter will always be zero. + /// The value is the cumulative `SO_RXQ_OVFL` count the kernel attaches + /// to datagrams read from the wildcard listen socket, so it covers that + /// socket only, not the per-peer connected sockets. It is updated only + /// as that socket is read, so it stops moving whenever the listen socket + /// is not being read. It is wired only on Linux; elsewhere (Darwin, + /// Windows, other Unix) it stays zero. pub fn set_kernel_drops(&self, drops: u64) { self.kernel_drops.store(drops, Ordering::Relaxed); } From 29779f5108f21ff332f503898966673fb6ee20b6 Mon Sep 17 00:00:00 2001 From: Johnathan Corgan Date: Sun, 4 Oct 2026 22:19:50 +0000 Subject: [PATCH 2/3] Changelog: fourth v0.5.3 landing batch --- CHANGELOG.md | 33 ++++++++++++++++++++++++++++++++- 1 file changed, 32 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 985fa651..48fe6496 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -85,6 +85,34 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - An Ethernet peer's address is always shown as a colon-separated MAC address in `fipsctl show links` and in log lines. An address whose six bytes happened to be valid UTF-8 was printed as text instead. +- The node no longer dials from its receive loop. When a peer's TCP, Tor or + Nym connection closed before the node answered or resent a handshake or + rekey message on it, the send dialed the peer's address and the receive + loop waited out the whole connect timeout (5 s by default on TCP) before + handling anything else, one send after another. For an inbound connection + that address is the peer's source port, where nothing listens. Meanwhile + UDP receive queues filled, other peers' links timed out and dropped, and the + log showed a `transport timeout` warning on `Failed to send msg2` or + `Failed to send rekey msg2` about every 5 s (#176). These sends now use only + a connection the transport already holds, and fail at once without one. For + a peer this node dialed, a connect is started in the background and the + next send uses it; an inbound peer's address is never dialed. +- `show_transports` (`fipsctl show transports`) reports transport counters as + they stand when asked. They were a copy refreshed by the node's periodic + tick, so when the receive loop was too busy for the tick to run they stopped + moving with nothing to show it: in #176, `connect_timeouts` read 0 while the + log recorded hundreds of timeouts. The output is unchanged. +- The UDP transport's `packets_recv` and `bytes_recv` now count datagrams + received on per-peer connected sockets, and `packets_sent`, `bytes_sent` and + `send_errors` count the data frames the encrypt workers send. Both were + missed, so on a node with connected UDP on (the Linux and macOS default) + the counters were far below the traffic the transport carried. +- A failed connect made in the background by TCP, Tor or Nym is now counted, + as a failed inline connect is. TCP counted none, Tor missed timeouts, and + Nym missed timeouts and SOCKS5 errors. TCP's `connect_refused` counts every + connect that fails before its timeout, not only a refused one: an + unreachable host or network, a reset or any other connect error lands there + too, with the error in the debug log. #### macOS @@ -212,7 +240,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 formed or rekeyed. Anyone holding a copy of a peer's msg1 could have the node send a msg2 to an address of their choosing. A peer whose address changed is answered at the old one until its next frame from the new - address arrives. A msg1 from a node this one holds no link with, or one + address arrives. Over TCP, Tor and Nym, once the established connection has + closed, a msg1 that arrived on a new connection to the same transport is + answered on that connection; the peer opened it, so only the peer receives + the answer. A msg1 from a node this one holds no link with, or one that carries a different startup epoch, still starts a new link and is answered at its source, as any new connection is. - The SHA-256 and HMAC states used by the Noise handshake are now cleared when From 5f60d2b02e3b91492059f01231a18d248320251b Mon Sep 17 00:00:00 2001 From: Johnathan Corgan Date: Sun, 4 Oct 2026 22:29:04 +0000 Subject: [PATCH 3/3] Finish the non-dialing send on master's own paths, and tidy what the merge left The two node-side inline sends on the UDP encrypt-worker fallback paths use send_existing. Both only ever see a UDP handle, for which send_existing forwards to the same send, so behaviour is unchanged; it leaves no node-side caller of the dialing send. The medium-change heartbeat note said the send after a failed write redials the peer. The link send no longer dials: once the stranded connection is evicted, the next send fails at once and starts a background connect, and only toward an address this node dialed. The classification test lists NotConnected among the terminal errors, so flipping it to transient fails a test that names the change. The rx-stall tests drop the blocking read timeouts their polling read never used, the Nym send_existing tests reuse the existing mock-proxy fixture, and the SOCKS5 pool tests use the shared wait_until helper. --- src/node/handlers/netmon.rs | 11 ++++++----- src/node/handlers/session.rs | 2 +- src/node/mod.rs | 2 +- src/node/tests/rx_stall.rs | 9 +-------- src/transport/mod.rs | 2 ++ src/transport/nym/mod.rs | 38 ++---------------------------------- src/transport/socks5/pool.rs | 15 +------------- 7 files changed, 14 insertions(+), 65 deletions(-) diff --git a/src/node/handlers/netmon.rs b/src/node/handlers/netmon.rs index fb77735d..8e658c10 100644 --- a/src/node/handlers/netmon.rs +++ b/src/node/handlers/netmon.rs @@ -167,11 +167,12 @@ impl Node { /// /// So a peer on TCP, Tor, Nym or BLE keeps the periodic heartbeat it had /// before this detector existed, and `link_dead_timeout_secs` remains the - /// backstop. Note that it does *not* recover by redialling: `send_async` - /// only dials when the pool holds no connection for the address, and a - /// connection stranded by a medium change is still in the pool. It is - /// evicted after a write to it fails, so the redial happens on the send - /// after the failure, not on the first one. Doing better for them means + /// backstop. Note that it does *not* recover by redialling. The link send + /// never dials, and a connection stranded by a medium change is still in + /// the pool until its writer's write to it fails. The send after that + /// finds no connection and fails, starting a background connect only if + /// this node dialed the peer at that address, and a later send uses it; + /// a peer that dialed in is never redialled. Doing better for them means /// dropping the stale connection /// rather than writing into it, which is a different change with a real /// cost behind it — a Tor peer pays a fresh circuit — and is not this one. diff --git a/src/node/handlers/session.rs b/src/node/handlers/session.rs index bf2aaec6..422f9b55 100644 --- a/src/node/handlers/session.rs +++ b/src/node/handlers/session.rs @@ -2930,7 +2930,7 @@ impl Node { debug!(next_hop = %next_hop_addr, "Transport gone before inline send of session data"); return; }; - if let Err(error) = transport.send(remote_addr, &wire).await { + if let Err(error) = transport.send_existing(remote_addr, &wire).await { debug!(next_hop = %next_hop_addr, %error, "Inline send of session data failed"); } } diff --git a/src/node/mod.rs b/src/node/mod.rs index f12b60e6..91c0d21b 100644 --- a/src/node/mod.rs +++ b/src/node/mod.rs @@ -3941,7 +3941,7 @@ impl Node { reason: format!("encryption failed: {}", e), })?; transport - .send(&remote_addr, &wire) + .send_existing(&remote_addr, &wire) .await .map_err(|e| link_send_error(*node_addr, e))? } diff --git a/src/node/tests/rx_stall.rs b/src/node/tests/rx_stall.rs index 58711df3..08c2236e 100644 --- a/src/node/tests/rx_stall.rs +++ b/src/node/tests/rx_stall.rs @@ -148,11 +148,7 @@ async fn prime_link(node: &Node, bh: &Blackhole) -> std::net::TcpStream { tokio::time::sleep(Duration::from_millis(10)).await; } let (accepted, _) = bh.listener.accept().unwrap(); - let accepted = std::net::TcpStream::from(accepted); - accepted - .set_read_timeout(Some(Duration::from_millis(1000))) - .unwrap(); - accepted + std::net::TcpStream::from(accepted) } /// Close the node's connection to `bh` from the far end, after taking the @@ -581,9 +577,6 @@ async fn msg1_resend_to_dead_outbound_leg_recovers_after_background_connect() { } let (accepted, _) = bh.listener.accept().unwrap(); let mut accepted = std::net::TcpStream::from(accepted); - accepted - .set_read_timeout(Some(Duration::from_millis(1000))) - .unwrap(); println!( "msg1 resend sent after {:?} over the background connect", start.elapsed() diff --git a/src/transport/mod.rs b/src/transport/mod.rs index cd9286e4..a0227300 100644 --- a/src/transport/mod.rs +++ b/src/transport/mod.rs @@ -1996,6 +1996,8 @@ mod tests { // answer, not this node's inability to transmit. TransportError::Timeout, TransportError::ConnectionRefused, + // The connection is gone and nothing will bring it back. + TransportError::NotConnected, ] { assert!( !terminal.is_transient(), diff --git a/src/transport/nym/mod.rs b/src/transport/nym/mod.rs index c7cbf3c2..0c0a34be 100644 --- a/src/transport/nym/mod.rs +++ b/src/transport/nym/mod.rs @@ -1286,45 +1286,11 @@ mod tests { dest.stop_async().await.unwrap(); } - /// A destination TCP transport behind a mock SOCKS5 proxy, and a - /// started Nym transport pointed at the proxy. - async fn nym_behind_mock_proxy() -> ( - NymTransport, - TcpTransport, - crate::transport::PacketRx, - TransportAddr, - ) { - let (dest_tx, dest_rx) = packet_channel(32); - let dest_config = TcpConfig { - bind_addr: Some("127.0.0.1:0".to_string()), - ..Default::default() - }; - let mut dest = TcpTransport::new(TransportId::new(100), None, dest_config, dest_tx); - dest.start_async().await.unwrap(); - let dest_addr = dest.local_addr().unwrap(); - - let mock = MockSocks5Server::new(dest_addr).await.unwrap(); - let proxy_addr = mock.addr(); - let _proxy_handle = mock.spawn(); - - let (tx, _rx) = packet_channel(32); - let config = NymConfig { - socks5_addr: Some(proxy_addr.to_string()), - startup_timeout_secs: Some(5), - connect_timeout_ms: Some(5000), - ..Default::default() - }; - let mut t = NymTransport::new(TransportId::new(200), None, config, tx); - t.start_async().await.unwrap(); - let target = TransportAddr::from_string(&dest_addr.to_string()); - (t, dest, dest_rx, target) - } - /// With no pooled connection and no connect under way, `send_existing` /// fails with `NotConnected` and opens nothing. #[tokio::test] async fn send_existing_without_connection_fails_fast_and_dials_nothing() { - let (mut t, mut dest, _dest_rx, target) = nym_behind_mock_proxy().await; + let (mut dest, _dest_rx, mut t, target) = nym_via_mock_proxy().await; let result = t.send_existing(&target, &build_msg1_frame()).await; @@ -1352,7 +1318,7 @@ mod tests { /// carries the send, with no second connection opened. #[tokio::test] async fn send_existing_promotes_a_finished_background_connect_and_sends_on_it() { - let (mut t, mut dest, mut dest_rx, target) = nym_behind_mock_proxy().await; + let (mut dest, mut dest_rx, mut t, target) = nym_via_mock_proxy().await; t.connect_async(&target).await.unwrap(); let mut waited = 0; diff --git a/src/transport/socks5/pool.rs b/src/transport/socks5/pool.rs index d348184f..6163337d 100644 --- a/src/transport/socks5/pool.rs +++ b/src/transport/socks5/pool.rs @@ -417,6 +417,7 @@ pub(crate) async fn proxied_receive_loop( #[cfg(test)] mod tests { use super::*; + use crate::testutil::wait_until; use crate::transport::packet_channel; use crate::transport::stream::{next_conn_id, park_writer}; use portable_atomic::{AtomicU64, Ordering}; @@ -463,20 +464,6 @@ mod tests { } } - /// Poll `f` every 10ms until it holds or `limit` elapses. - async fn wait_until bool>(mut f: F, limit: Duration) -> bool { - let deadline = Instant::now() + limit; - loop { - if f() { - return true; - } - if Instant::now() >= deadline { - return false; - } - tokio::time::sleep(Duration::from_millis(10)).await; - } - } - /// A writer whose write fails must not remove a newer connection that has /// taken its address in the pool, nor run `on_remove` for it. #[tokio::test]