From 754abf213504b0e3594a0d38f079b8a114266fda Mon Sep 17 00:00:00 2001 From: John Smith Date: Wed, 21 Jun 2023 13:40:12 -0400 Subject: [PATCH] fix binding issues --- Cargo.lock | 7 ++ veilid-cli/src/command_processor.rs | 25 ++++-- veilid-core/src/attachment_manager.rs | 1 + veilid-core/src/network_manager/mod.rs | 2 +- .../src/network_manager/native/network_tcp.rs | 9 ++ .../native/protocol/sockets.rs | 12 +-- .../network_manager/native/start_protocols.rs | 19 +++- veilid-core/src/routing_table/find_peers.rs | 2 +- veilid-core/src/veilid_api/debug.rs | 16 +--- veilid-core/src/veilid_api/routing_context.rs | 10 ++- veilid-tools/Cargo.toml | 1 + veilid-tools/src/lib.rs | 2 + veilid-tools/src/network_result.rs | 86 +++++++++++-------- 13 files changed, 121 insertions(+), 71 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 7de49121..f467ee15 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2071,6 +2071,12 @@ dependencies = [ "spin 0.9.8", ] +[[package]] +name = "fn_name" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "528a0eb35b41b895aef1afed5ab28659084118e730edc72f033e76fb71666dbb" + [[package]] name = "fnv" version = "1.0.7" @@ -6591,6 +6597,7 @@ dependencies = [ "cfg-if 1.0.0", "console_error_panic_hook", "eyre", + "fn_name", "futures-util", "jni 0.21.1", "jni-sys", diff --git a/veilid-cli/src/command_processor.rs b/veilid-cli/src/command_processor.rs index 5bd05bd7..c6ab46c7 100644 --- a/veilid-cli/src/command_processor.rs +++ b/veilid-cli/src/command_processor.rs @@ -107,14 +107,21 @@ impl CommandProcessor { self.ui_sender().add_node_event( Level::Info, r#"Commands: -exit/quit - exit the client -disconnect - disconnect the client from the Veilid node -shutdown - shut the server down -attach - attach the server to the Veilid network -detach - detach the server from the Veilid network -debug - send a debugging command to the Veilid server -change_log_level - change the log level for a tracing layer -reply - reply to an AppCall not handled directly by the server +exit/quit exit the client +disconnect disconnect the client from the Veilid node +shutdown shut the server down +attach attach the server to the Veilid network +detach detach the server from the Veilid network +debug [command] send a debugging command to the Veilid server +change_log_level change the log level for a tracing layer + layers include: + all, terminal, system, api, file, otlp + levels include: + error, warn, info, debug, trace +reply reply to an AppCall not handled directly by the server + must be exact call id reported in VeilidUpdate + can be a string (left trimmed) or + it can start with a '#' followed by a string of undelimited hex bytes "# .to_owned(), ); @@ -188,7 +195,7 @@ reply - reply to an AppCall not handled directly by the server spawn_detached_local(async move { match capi.server_debug(rest.unwrap_or_default()).await { Ok(output) => { - ui.add_node_event(Level::Debug, output); + ui.add_node_event(Level::Info, output); ui.send_callback(callback); } Err(e) => { diff --git a/veilid-core/src/attachment_manager.rs b/veilid-core/src/attachment_manager.rs index a373bea2..1e92567d 100644 --- a/veilid-core/src/attachment_manager.rs +++ b/veilid-core/src/attachment_manager.rs @@ -196,6 +196,7 @@ impl AttachmentManager { if let Err(err) = netman.startup().await { error!("network startup failed: {}", err); netman.shutdown().await; + restart = true; break; } diff --git a/veilid-core/src/network_manager/mod.rs b/veilid-core/src/network_manager/mod.rs index 783d92e1..68623a9e 100644 --- a/veilid-core/src/network_manager/mod.rs +++ b/veilid-core/src/network_manager/mod.rs @@ -906,7 +906,7 @@ impl NetworkManager { return Ok(NetworkResult::timeout()); } ReceiptEvent::Cancelled => { - bail!("reverse connect receipt cancelled from {:?}", target_nr); + return Ok(NetworkResult::no_connection_other(format!("reverse connect receipt cancelled from {}", target_nr))) } }; diff --git a/veilid-core/src/network_manager/native/network_tcp.rs b/veilid-core/src/network_manager/native/network_tcp.rs index b537160a..6d717ad8 100644 --- a/veilid-core/src/network_manager/native/network_tcp.rs +++ b/veilid-core/src/network_manager/native/network_tcp.rs @@ -115,6 +115,15 @@ impl Network { // tcp_stream.peer_addr().unwrap(), // ); + if let Err(e) = tcp_stream.set_linger(Some(core::time::Duration::from_secs(0))) { + log_net!(debug "Couldn't set TCP linger: {}", e); + return; + } + if let Err(e) = tcp_stream.set_nodelay(true) { + log_net!(debug "Couldn't set TCP nodelay: {}", e); + return; + } + let listener_state = listener_state.clone(); let connection_manager = connection_manager.clone(); diff --git a/veilid-core/src/network_manager/native/protocol/sockets.rs b/veilid-core/src/network_manager/native/protocol/sockets.rs index 608e19b5..71ee5676 100644 --- a/veilid-core/src/network_manager/native/protocol/sockets.rs +++ b/veilid-core/src/network_manager/native/protocol/sockets.rs @@ -33,7 +33,7 @@ cfg_if! { } } -#[instrument(level = "trace", ret, err)] +#[instrument(level = "trace", ret)] pub fn new_unbound_shared_udp_socket(domain: Domain) -> io::Result { let socket = Socket::new(domain, Type::DGRAM, Some(Protocol::UDP))?; if domain == Domain::IPV6 { @@ -49,7 +49,7 @@ pub fn new_unbound_shared_udp_socket(domain: Domain) -> io::Result { Ok(socket) } -#[instrument(level = "trace", ret, err)] +#[instrument(level = "trace", ret)] pub fn new_bound_shared_udp_socket(local_address: SocketAddr) -> io::Result { let domain = Domain::for_address(local_address); let socket = new_unbound_shared_udp_socket(domain)?; @@ -61,7 +61,7 @@ pub fn new_bound_shared_udp_socket(local_address: SocketAddr) -> io::Result io::Result { let domain = Domain::for_address(local_address); let socket = Socket::new(domain, Type::DGRAM, Some(Protocol::UDP))?; @@ -95,7 +95,7 @@ pub fn new_bound_first_udp_socket(local_address: SocketAddr) -> io::Result io::Result { let socket = Socket::new(domain, Type::STREAM, Some(Protocol::TCP))?; if let Err(e) = socket.set_linger(Some(core::time::Duration::from_secs(0))) { @@ -117,7 +117,7 @@ pub fn new_unbound_shared_tcp_socket(domain: Domain) -> io::Result { Ok(socket) } -#[instrument(level = "trace", ret, err)] +#[instrument(level = "trace", ret)] pub fn new_bound_shared_tcp_socket(local_address: SocketAddr) -> io::Result { let domain = Domain::for_address(local_address); let socket = new_unbound_shared_tcp_socket(domain)?; @@ -129,7 +129,7 @@ pub fn new_bound_shared_tcp_socket(local_address: SocketAddr) -> io::Result io::Result { let domain = Domain::for_address(local_address); diff --git a/veilid-core/src/network_manager/native/start_protocols.rs b/veilid-core/src/network_manager/native/start_protocols.rs index 76cdaf68..5d4ce372 100644 --- a/veilid-core/src/network_manager/native/start_protocols.rs +++ b/veilid-core/src/network_manager/native/start_protocols.rs @@ -243,7 +243,24 @@ impl Network { bail!("No valid listen address: {}", listen_address); } let port = sockaddrs[0].port(); - if !self.bind_first_tcp_port(port) { + + let mut attempts = 10; + let mut success = false; + while attempts >= 0 { + if self.bind_first_tcp_port(port) { + success = true; + break; + } + attempts -= 1; + + // Wait 5 seconds before trying again + log_net!(debug + "Binding TCP port at {} failed, waiting. Attempts remaining = {}", + port, attempts + ); + sleep(5000).await + } + if !success { bail!("Could not find free tcp port to listen on"); } Ok((port, sockaddrs.iter().map(|s| s.ip()).collect())) diff --git a/veilid-core/src/routing_table/find_peers.rs b/veilid-core/src/routing_table/find_peers.rs index 2373e9be..2a240e26 100644 --- a/veilid-core/src/routing_table/find_peers.rs +++ b/veilid-core/src/routing_table/find_peers.rs @@ -5,7 +5,7 @@ impl RoutingTable { pub fn find_all_closest_peers(&self, key: TypedKey) -> NetworkResult> { let Some(own_peer_info) = self.get_own_peer_info(RoutingDomain::PublicInternet) else { // Our own node info is not yet available, drop this request. - return NetworkResult::service_unavailable(); + return NetworkResult::service_unavailable("Not finding closest peers because our peer info is not yet available"); }; // find N nodes closest to the target node in our routing table diff --git a/veilid-core/src/veilid_api/debug.rs b/veilid-core/src/veilid_api/debug.rs index 436eec3b..36ae4d4a 100644 --- a/veilid-core/src/veilid_api/debug.rs +++ b/veilid-core/src/veilid_api/debug.rs @@ -591,20 +591,8 @@ impl VeilidAPI { .map_err(VeilidAPIError::internal)? { NetworkResult::Value(v) => v, - NetworkResult::Timeout => { - return Ok("Timeout".to_owned()); - } - NetworkResult::ServiceUnavailable => { - return Ok("ServiceUnavailable".to_owned()); - } - NetworkResult::NoConnection(e) => { - return Ok(format!("NoConnection({})", e)); - } - NetworkResult::AlreadyExists(e) => { - return Ok(format!("AlreadyExists({})", e)); - } - NetworkResult::InvalidMessage(e) => { - return Ok(format!("InvalidMessage({})", e)); + r => { + return Ok(r.to_string()); } }; diff --git a/veilid-core/src/veilid_api/routing_context.rs b/veilid-core/src/veilid_api/routing_context.rs index e73e54ca..26a8cc12 100644 --- a/veilid-core/src/veilid_api/routing_context.rs +++ b/veilid-core/src/veilid_api/routing_context.rs @@ -148,7 +148,10 @@ impl RoutingContext { let answer = match rpc_processor.rpc_call_app_call(dest, request).await { Ok(NetworkResult::Value(v)) => v, Ok(NetworkResult::Timeout) => apibail_timeout!(), - Ok(NetworkResult::ServiceUnavailable) => apibail_try_again!(), + Ok(NetworkResult::ServiceUnavailable(e)) => { + log_network_result!(format!("app_call: ServiceUnavailable({})", e)); + apibail_try_again!() + } Ok(NetworkResult::NoConnection(e)) | Ok(NetworkResult::AlreadyExists(e)) => { apibail_no_connection!(e); } @@ -173,7 +176,10 @@ impl RoutingContext { match rpc_processor.rpc_call_app_message(dest, message).await { Ok(NetworkResult::Value(())) => {} Ok(NetworkResult::Timeout) => apibail_timeout!(), - Ok(NetworkResult::ServiceUnavailable) => apibail_try_again!(), + Ok(NetworkResult::ServiceUnavailable(e)) => { + log_network_result!(format!("app_message: ServiceUnavailable({})", e)); + apibail_try_again!() + } Ok(NetworkResult::NoConnection(e)) | Ok(NetworkResult::AlreadyExists(e)) => { apibail_no_connection!(e); } diff --git a/veilid-tools/Cargo.toml b/veilid-tools/Cargo.toml index 7e3f3d12..1deb901a 100644 --- a/veilid-tools/Cargo.toml +++ b/veilid-tools/Cargo.toml @@ -35,6 +35,7 @@ stop-token = { version = "^0", default-features = false } rand = "^0.7" rust-fsm = "^0" backtrace = "^0" +fn_name = "^0" # Dependencies for native builds only # Linux, Windows, Mac, iOS, Android diff --git a/veilid-tools/src/lib.rs b/veilid-tools/src/lib.rs index 253e6c8b..0e2f1d94 100644 --- a/veilid-tools/src/lib.rs +++ b/veilid-tools/src/lib.rs @@ -134,6 +134,8 @@ use parking_lot::*; use stop_token::*; use thiserror::Error as ThisError; +pub use fn_name; + // For iOS tests #[no_mangle] pub extern "C" fn main_rs() {} diff --git a/veilid-tools/src/network_result.rs b/veilid-tools/src/network_result.rs index 437000bc..e73a0599 100644 --- a/veilid-tools/src/network_result.rs +++ b/veilid-tools/src/network_result.rs @@ -68,7 +68,7 @@ impl NetworkResultResultExt for NetworkResult> { fn into_result_network_result(self) -> Result, E> { match self { NetworkResult::Timeout => Ok(NetworkResult::::Timeout), - NetworkResult::ServiceUnavailable => Ok(NetworkResult::::ServiceUnavailable), + NetworkResult::ServiceUnavailable(s) => Ok(NetworkResult::::ServiceUnavailable(s)), NetworkResult::NoConnection(e) => Ok(NetworkResult::::NoConnection(e)), NetworkResult::AlreadyExists(e) => Ok(NetworkResult::::AlreadyExists(e)), NetworkResult::InvalidMessage(s) => Ok(NetworkResult::::InvalidMessage(s)), @@ -161,7 +161,7 @@ impl FoldedNetworkResultExt for io::Result> { #[must_use] pub enum NetworkResult { Timeout, - ServiceUnavailable, + ServiceUnavailable(String), NoConnection(io::Error), AlreadyExists(io::Error), InvalidMessage(String), @@ -172,8 +172,8 @@ impl NetworkResult { pub fn timeout() -> Self { Self::Timeout } - pub fn service_unavailable() -> Self { - Self::ServiceUnavailable + pub fn service_unavailable(s: S) -> Self { + Self::ServiceUnavailable(s.to_string()) } pub fn no_connection(e: io::Error) -> Self { Self::NoConnection(e) @@ -206,7 +206,7 @@ impl NetworkResult { pub fn map X>(self, f: F) -> NetworkResult { match self { Self::Timeout => NetworkResult::::Timeout, - Self::ServiceUnavailable => NetworkResult::::ServiceUnavailable, + Self::ServiceUnavailable(s) => NetworkResult::::ServiceUnavailable(s), Self::NoConnection(e) => NetworkResult::::NoConnection(e), Self::AlreadyExists(e) => NetworkResult::::AlreadyExists(e), Self::InvalidMessage(s) => NetworkResult::::InvalidMessage(s), @@ -216,9 +216,9 @@ impl NetworkResult { pub fn into_result(self) -> Result { match self { Self::Timeout => Err(io::Error::new(io::ErrorKind::TimedOut, "Timed out")), - Self::ServiceUnavailable => Err(io::Error::new( + Self::ServiceUnavailable(s) => Err(io::Error::new( io::ErrorKind::NotFound, - "Service unavailable", + format!("Service unavailable: {}", s), )), Self::NoConnection(e) => Err(e), Self::AlreadyExists(e) => Err(e), @@ -244,7 +244,7 @@ impl Debug for NetworkResult { fn fmt(&self, f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result { match self { Self::Timeout => write!(f, "Timeout"), - Self::ServiceUnavailable => write!(f, "ServiceUnavailable"), + Self::ServiceUnavailable(s) => f.debug_tuple("ServiceUnavailable").field(s).finish(), Self::NoConnection(e) => f.debug_tuple("NoConnection").field(e).finish(), Self::AlreadyExists(e) => f.debug_tuple("AlreadyExists").field(e).finish(), Self::InvalidMessage(s) => f.debug_tuple("InvalidMessage").field(s).finish(), @@ -257,7 +257,7 @@ impl Display for NetworkResult { fn fmt(&self, f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result { match self { Self::Timeout => write!(f, "Timeout"), - Self::ServiceUnavailable => write!(f, "ServiceUnavailable"), + Self::ServiceUnavailable(s) => write!(f, "ServiceUnavailable({})", s), Self::NoConnection(e) => write!(f, "NoConnection({})", e.kind()), Self::AlreadyExists(e) => write!(f, "AlreadyExists({})", e.kind()), Self::InvalidMessage(s) => write!(f, "InvalidMessage({})", s), @@ -276,7 +276,7 @@ macro_rules! network_result_try { ($r: expr) => { match $r { NetworkResult::Timeout => return Ok(NetworkResult::Timeout), - NetworkResult::ServiceUnavailable => return Ok(NetworkResult::ServiceUnavailable), + NetworkResult::ServiceUnavailable(s) => return Ok(NetworkResult::ServiceUnavailable(s)), NetworkResult::NoConnection(e) => return Ok(NetworkResult::NoConnection(e)), NetworkResult::AlreadyExists(e) => return Ok(NetworkResult::AlreadyExists(e)), NetworkResult::InvalidMessage(s) => return Ok(NetworkResult::InvalidMessage(s)), @@ -289,9 +289,9 @@ macro_rules! network_result_try { $f; return Ok(NetworkResult::Timeout); } - NetworkResult::ServiceUnavailable => { + NetworkResult::ServiceUnavailable(s) => { $f; - return Ok(NetworkResult::ServiceUnavailable); + return Ok(NetworkResult::ServiceUnavailable(s)); } NetworkResult::NoConnection(e) => { $f; @@ -313,22 +313,22 @@ macro_rules! network_result_try { #[macro_export] macro_rules! log_network_result { ($text:expr) => { - cfg_if::cfg_if! { - if #[cfg(debug_assertions)] { - info!(target: "network_result", "{}", $text) - } else { + // cfg_if::cfg_if! { + // if #[cfg(debug_assertions)] { + // info!(target: "network_result", "{}", $text) + // } else { debug!(target: "network_result", "{}", $text) - } - } + // } + // } }; ($fmt:literal, $($arg:expr),+) => { - cfg_if::cfg_if! { - if #[cfg(debug_assertions)] { - info!(target: "network_result", $fmt, $($arg),+); - } else { + // cfg_if::cfg_if! { + // if #[cfg(debug_assertions)] { + // info!(target: "network_result", $fmt, $($arg),+); + // } else { debug!(target: "network_result", $fmt, $($arg),+); - } - } + // } + // } }; } @@ -337,49 +337,61 @@ macro_rules! network_result_value_or_log { ($r: expr => $f:tt) => { match $r { NetworkResult::Timeout => { - log_network_result!("{} at {}@{}:{}", "Timeout", file!(), line!(), column!()); - $f - } - NetworkResult::ServiceUnavailable => { log_network_result!( - "{} at {}@{}:{}", - "ServiceUnavailable", + "{} at {}@{}:{} in {}", + "Timeout", file!(), line!(), - column!() + column!(), + fn_name::uninstantiated!() + ); + $f + } + NetworkResult::ServiceUnavailable(s) => { + log_network_result!( + "{}({}) at {}@{}:{} in {}", + "ServiceUnavailable", + s, + file!(), + line!(), + column!(), + fn_name::uninstantiated!() ); $f } NetworkResult::NoConnection(e) => { log_network_result!( - "{}({}) at {}@{}:{}", + "{}({}) at {}@{}:{} in {}", "No connection", e.to_string(), file!(), line!(), - column!() + column!(), + fn_name::uninstantiated!() ); $f } NetworkResult::AlreadyExists(e) => { log_network_result!( - "{}({}) at {}@{}:{}", + "{}({}) at {}@{}:{} in {}", "Already exists", e.to_string(), file!(), line!(), - column!() + column!(), + fn_name::uninstantiated!() ); $f } NetworkResult::InvalidMessage(s) => { log_network_result!( - "{}({}) at {}@{}:{}", + "{}({}) at {}@{}:{} in {}", "Invalid message", s, file!(), line!(), - column!() + column!(), + fn_name::uninstantiated!() ); $f }