fixes

veilid-core/src/connection_manager.rs

@@ -178,7 +178,7 @@ impl ConnectionManager {
                         match res {
                             Ok(v) => v,
                             Err(e) => {
-                                log_net!(error e);
+                                log_net!(debug e);
                                 break;
                             }
                         }

veilid-core/src/dht/receipt.rs

@@ -4,6 +4,7 @@ use super::envelope::{MAX_VERSION, MIN_VERSION};
 use super::key::*;
 use crate::xx::*;
 use core::convert::TryInto;
+use data_encoding::BASE64URL_NOPAD;
 
 // #[repr(C, packed)]
 // struct ReceiptHeader {
@@ -32,6 +33,16 @@ pub const MIN_RECEIPT_SIZE: usize = 128;
 pub const RECEIPT_MAGIC: &[u8; 4] = b"RCPT";
 pub type ReceiptNonce = [u8; 24];
 
+pub trait Encodable {
+    fn encode(&self) -> String;
+}
+
+impl Encodable for ReceiptNonce {
+    fn encode(&self) -> String {
+        BASE64URL_NOPAD.encode(self)
+    }
+}
+
 #[derive(Debug, Clone, PartialEq, Eq, Default)]
 pub struct Receipt {
     version: u8,

veilid-core/src/intf/native/network/network_class_discovery.rs

@@ -4,16 +4,24 @@ use crate::intf::*;
 use crate::routing_table::*;
 use crate::*;
 
+use futures_util::stream::FuturesUnordered;
+use futures_util::FutureExt;
+
+struct DetectedPublicDialInfo {
+    dial_info: DialInfo,
+    class: DialInfoClass,
+}
 struct DiscoveryContextInner {
-    network_class: Option<NetworkClass>,
     // per-protocol
     intf_addrs: Option<Vec<SocketAddress>>,
     protocol_type: Option<ProtocolType>,
     address_type: Option<AddressType>,
-    low_level_protocol_type: Option<ProtocolType>,
     external1_dial_info: Option<DialInfo>,
     external1: Option<SocketAddress>,
     node_b: Option<NodeRef>,
+    // detected public dialinfo
+    detected_network_class: Option<NetworkClass>,
+    detected_public_dial_info: Option<DetectedPublicDialInfo>,
 }
 
 pub struct DiscoveryContext {
@@ -28,15 +36,15 @@ impl DiscoveryContext {
             routing_table,
             net,
             inner: Arc::new(Mutex::new(DiscoveryContextInner {
-                network_class: None,
                 // per-protocol
                 intf_addrs: None,
                 protocol_type: None,
                 address_type: None,
-                low_level_protocol_type: None,
                 external1_dial_info: None,
                 external1: None,
                 node_b: None,
+                detected_network_class: None,
+                detected_public_dial_info: None,
             })),
         }
     }
@@ -45,16 +53,14 @@ impl DiscoveryContext {
     // Utilities
 
     // Pick the best network class we have seen so far
-    pub fn upgrade_network_class(&self, network_class: NetworkClass) {
+    pub fn set_detected_network_class(&self, network_class: NetworkClass) {
         let mut inner = self.inner.lock();
+        inner.detected_network_class = Some(network_class);
+    }
 
-        if let Some(old_nc) = inner.network_class {
+    pub fn set_detected_public_dial_info(&self, dial_info: DialInfo, class: DialInfoClass) {
-            if network_class < old_nc {
+        let mut inner = self.inner.lock();
-                inner.network_class = Some(network_class);
+        inner.detected_public_dial_info = Some(DetectedPublicDialInfo { dial_info, class });
-            }
-        } else {
-            inner.network_class = Some(network_class);
-        }
     }
 
     // Ask for a public address check from a particular noderef
@@ -66,7 +72,11 @@ impl DiscoveryContext {
                 "failed to get status answer from {:?}",
                 node_ref
             ))
-            .map(|sa| sa.sender_info.socket_address)
+            .map(|sa| {
+                let ret = sa.sender_info.socket_address;
+                log_net!("request_public_address: {:?}", ret);
+                ret
+            })
             .unwrap_or(None)
     }
 
@@ -169,12 +179,6 @@ impl DiscoveryContext {
         inner.intf_addrs = Some(intf_addrs);
         inner.protocol_type = Some(protocol_type);
         inner.address_type = Some(address_type);
-        inner.low_level_protocol_type = Some(match protocol_type {
-            ProtocolType::UDP => ProtocolType::UDP,
-            ProtocolType::TCP => ProtocolType::TCP,
-            ProtocolType::WS => ProtocolType::TCP,
-            ProtocolType::WSS => ProtocolType::TCP,
-        });
         inner.external1_dial_info = None;
         inner.external1 = None;
         inner.node_b = None;
@@ -193,6 +197,7 @@ impl DiscoveryContext {
         {
             None => {
                 // If we can't get an external address, exit but don't throw an error so we can try again later
+                log_net!(debug "couldn't get external address 1");
                 return false;
             }
             Some(v) => v,
@@ -204,6 +209,8 @@ impl DiscoveryContext {
         inner.external1 = Some(external1);
         inner.node_b = Some(node_b);
 
+        log_net!(debug "external1_dial_info: {:?}\nexternal1: {:?}\nnode_b: {:?}", inner.external1_dial_info, inner.external1, inner.node_b);
+
         true
     }
 
@@ -222,29 +229,17 @@ impl DiscoveryContext {
             .await
         {
             // Add public dial info with Direct dialinfo class
-            self.routing_table.register_dial_info(
+            self.set_detected_public_dial_info(external1_dial_info, DialInfoClass::Direct);
-                RoutingDomain::PublicInternet,
-                external1_dial_info,
-                DialInfoClass::Direct,
-            )?;
         }
         // Attempt a UDP port mapping via all available and enabled mechanisms
         else if let Some(external_mapped_dial_info) = self.try_port_mapping().await {
             // Got a port mapping, let's use it
-            self.routing_table.register_dial_info(
+            self.set_detected_public_dial_info(external_mapped_dial_info, DialInfoClass::Mapped);
-                RoutingDomain::PublicInternet,
-                external_mapped_dial_info,
-                DialInfoClass::Mapped,
-            )?;
         } else {
             // Add public dial info with Blocked dialinfo class
-            self.routing_table.register_dial_info(
+            self.set_detected_public_dial_info(external1_dial_info, DialInfoClass::Blocked);
-                RoutingDomain::PublicInternet,
-                external1_dial_info,
-                DialInfoClass::Blocked,
-            )?;
         }
-        self.upgrade_network_class(NetworkClass::InboundCapable);
+        self.set_detected_network_class(NetworkClass::InboundCapable);
         Ok(())
     }
 
@@ -263,12 +258,8 @@ impl DiscoveryContext {
         // Attempt a UDP port mapping via all available and enabled mechanisms
         if let Some(external_mapped_dial_info) = self.try_port_mapping().await {
             // Got a port mapping, let's use it
-            self.routing_table.register_dial_info(
+            self.set_detected_public_dial_info(external_mapped_dial_info, DialInfoClass::Mapped);
-                RoutingDomain::PublicInternet,
+            self.set_detected_network_class(NetworkClass::InboundCapable);
-                external_mapped_dial_info,
-                DialInfoClass::Mapped,
-            )?;
-            self.upgrade_network_class(NetworkClass::InboundCapable);
 
             // No more retries
             return Ok(true);
@@ -283,13 +274,10 @@ impl DiscoveryContext {
         {
             // Yes, another machine can use the dial info directly, so Full Cone
             // Add public dial info with full cone NAT network class
-            self.routing_table.register_dial_info(
+            self.set_detected_public_dial_info(external1_dial_info, DialInfoClass::FullConeNAT);
-                RoutingDomain::PublicInternet,
+            self.set_detected_network_class(NetworkClass::InboundCapable);
-                external1_dial_info,
-                DialInfoClass::FullConeNAT,
-            )?;
-            self.upgrade_network_class(NetworkClass::InboundCapable);
 
+            // No more retries
             return Ok(true);
         }
 
@@ -310,7 +298,7 @@ impl DiscoveryContext {
         // If we have two different external addresses, then this is a symmetric NAT
         if external2 != external1 {
             // Symmetric NAT is outbound only, no public dial info will work
-            self.upgrade_network_class(NetworkClass::OutboundOnly);
+            self.set_detected_network_class(NetworkClass::OutboundOnly);
 
             // No more retries
             return Ok(true);
@@ -326,20 +314,18 @@ impl DiscoveryContext {
             .await
         {
             // Got a reply from a non-default port, which means we're only address restricted
-            self.routing_table.register_dial_info(
+            self.set_detected_public_dial_info(
-                RoutingDomain::PublicInternet,
                 external1_dial_info,
                 DialInfoClass::AddressRestrictedNAT,
-            )?;
+            );
         } else {
             // Didn't get a reply from a non-default port, which means we are also port restricted
-            self.routing_table.register_dial_info(
+            self.set_detected_public_dial_info(
-                RoutingDomain::PublicInternet,
                 external1_dial_info,
                 DialInfoClass::PortRestrictedNAT,
-            )?;
+            );
         }
-        self.upgrade_network_class(NetworkClass::InboundCapable);
+        self.set_detected_network_class(NetworkClass::InboundCapable);
 
         // Allow another retry because sometimes trying again will get us Full Cone NAT instead
         Ok(false)
@@ -442,42 +428,159 @@ impl Network {
     }
 
     pub async fn update_network_class_task_routine(self, _l: u64, _t: u64) -> Result<(), String> {
-        log_net!("updating network class");
+        log_net!("--- updating network class");
+
+        // Ensure we aren't trying to update this without clearing it first
+        let old_network_class = self.inner.lock().network_class;
+        assert_eq!(old_network_class, None);
 
         let protocol_config = self.inner.lock().protocol_config.unwrap_or_default();
-        let old_network_class = self.inner.lock().network_class;
+        let mut unord = FuturesUnordered::new();
-
-        let context = DiscoveryContext::new(self.routing_table(), self.clone());
 
         if protocol_config.inbound.contains(ProtocolType::UDP) {
-            self.update_ipv4_protocol_dialinfo(&context, ProtocolType::UDP)
+            // UDPv4
-                .await?;
+            unord.push(
-            self.update_ipv6_protocol_dialinfo(&context, ProtocolType::UDP)
+                async {
-                .await?;
+                    let udpv4_context = DiscoveryContext::new(self.routing_table(), self.clone());
+                    if let Err(e) = self
+                        .update_ipv4_protocol_dialinfo(&udpv4_context, ProtocolType::UDP)
+                        .await
+                    {
+                        log_net!(debug "Failed UDPv4 dialinfo discovery: {}", e);
+                        return None;
+                    }
+                    Some(udpv4_context)
+                }
+                .boxed(),
+            );
+
+            // UDPv6
+            unord.push(
+                async {
+                    let udpv6_context = DiscoveryContext::new(self.routing_table(), self.clone());
+                    if let Err(e) = self
+                        .update_ipv6_protocol_dialinfo(&udpv6_context, ProtocolType::UDP)
+                        .await
+                    {
+                        log_net!(debug "Failed UDPv6 dialinfo discovery: {}", e);
+                        return None;
+                    }
+                    Some(udpv6_context)
+                }
+                .boxed(),
+            );
         }
 
         if protocol_config.inbound.contains(ProtocolType::TCP) {
-            self.update_ipv4_protocol_dialinfo(&context, ProtocolType::TCP)
+            // TCPv4
-                .await?;
+            unord.push(
-            self.update_ipv6_protocol_dialinfo(&context, ProtocolType::TCP)
+                async {
-                .await?;
+                    let tcpv4_context = DiscoveryContext::new(self.routing_table(), self.clone());
+                    if let Err(e) = self
+                        .update_ipv4_protocol_dialinfo(&tcpv4_context, ProtocolType::TCP)
+                        .await
+                    {
+                        log_net!(debug "Failed TCPv4 dialinfo discovery: {}", e);
+                        return None;
+                    }
+                    Some(tcpv4_context)
+                }
+                .boxed(),
+            );
+
+            // TCPv6
+            unord.push(
+                async {
+                    let tcpv6_context = DiscoveryContext::new(self.routing_table(), self.clone());
+                    if let Err(e) = self
+                        .update_ipv6_protocol_dialinfo(&tcpv6_context, ProtocolType::TCP)
+                        .await
+                    {
+                        log_net!(debug "Failed TCPv6 dialinfo discovery: {}", e);
+                        return None;
+                    }
+                    Some(tcpv6_context)
+                }
+                .boxed(),
+            );
         }
 
         if protocol_config.inbound.contains(ProtocolType::WS) {
-            self.update_ipv4_protocol_dialinfo(&context, ProtocolType::WS)
+            // WS4
-                .await?;
+            unord.push(
-            self.update_ipv6_protocol_dialinfo(&context, ProtocolType::WS)
+                async {
-                .await?;
+                    let wsv4_context = DiscoveryContext::new(self.routing_table(), self.clone());
+                    if let Err(e) = self
+                        .update_ipv4_protocol_dialinfo(&wsv4_context, ProtocolType::WS)
+                        .await
+                    {
+                        log_net!(debug "Failed WSv4 dialinfo discovery: {}", e);
+                        return None;
+                    }
+                    Some(wsv4_context)
+                }
+                .boxed(),
+            );
+
+            // WSv6
+            unord.push(
+                async {
+                    let wsv6_context = DiscoveryContext::new(self.routing_table(), self.clone());
+                    if let Err(e) = self
+                        .update_ipv6_protocol_dialinfo(&wsv6_context, ProtocolType::TCP)
+                        .await
+                    {
+                        log_net!(debug "Failed WSv6 dialinfo discovery: {}", e);
+                        return None;
+                    }
+                    Some(wsv6_context)
+                }
+                .boxed(),
+            );
         }
 
-        let network_class = context.inner.lock().network_class;
+        // Wait for all discovery futures to complete and collect contexts
-        if network_class != old_network_class {
+        let mut contexts = Vec::<DiscoveryContext>::new();
+        let mut network_class = Option::<NetworkClass>::None;
+        while let Some(ctx) = unord.next().await {
+            if let Some(ctx) = ctx {
+                if let Some(nc) = ctx.inner.lock().detected_network_class {
+                    if let Some(last_nc) = network_class {
+                        if nc < last_nc {
+                            network_class = Some(nc);
+                        }
+                    } else {
+                        network_class = Some(nc);
+                    }
+                }
+
+                contexts.push(ctx);
+            }
+        }
+
+        // Get best network class
+        if network_class.is_some() {
+            // Update public dial info
+            let routing_table = self.routing_table();
+            for ctx in contexts {
+                let inner = ctx.inner.lock();
+                if let Some(pdi) = &inner.detected_public_dial_info {
+                    if let Err(e) = routing_table.register_dial_info(
+                        RoutingDomain::PublicInternet,
+                        pdi.dial_info.clone(),
+                        pdi.class,
+                    ) {
+                        log_net!(warn "Failed to register detected public dial info: {}", e);
+                    }
+                }
+            }
+            // Update network class
             self.inner.lock().network_class = network_class;
             log_net!(debug "network class changed to {:?}", network_class);
-        }
 
-        // send updates to everyone
+            // Send updates to everyone
-        self.routing_table().send_node_info_updates();
+            routing_table.send_node_info_updates();
+        }
 
         Ok(())
     }

veilid-core/src/receipt_manager.rs

@@ -310,6 +310,7 @@ impl ReceiptManager {
         expected_returns: u32,
         callback: impl ReceiptCallback,
     ) {
+        log_rpc!(debug "== New Multiple Receipt ({}) {} ", expected_returns, receipt.get_nonce().encode());
         let record = Arc::new(Mutex::new(ReceiptRecord::from_receipt(
             &receipt,
             expiration,
@@ -318,6 +319,8 @@ impl ReceiptManager {
         )));
         let mut inner = self.inner.lock();
         inner.receipts_by_nonce.insert(receipt.get_nonce(), record);
+
+        Self::update_next_oldest_timestamp(&mut *inner);
     }
 
     pub fn record_single_shot_receipt(
@@ -326,11 +329,15 @@ impl ReceiptManager {
         expiration: u64,
         eventual: ReceiptSingleShotType,
     ) {
+        log_rpc!(debug "== New SingleShot Receipt {}", receipt.get_nonce().encode());
+
         let record = Arc::new(Mutex::new(ReceiptRecord::from_single_shot_receipt(
             &receipt, expiration, eventual,
         )));
         let mut inner = self.inner.lock();
         inner.receipts_by_nonce.insert(receipt.get_nonce(), record);
+
+        Self::update_next_oldest_timestamp(&mut *inner);
     }
 
     fn update_next_oldest_timestamp(inner: &mut ReceiptManagerInner) {
@@ -350,6 +357,8 @@ impl ReceiptManager {
     }
 
     pub async fn cancel_receipt(&self, nonce: &ReceiptNonce) -> Result<(), String> {
+        log_rpc!(debug "== Cancel Receipt {}", nonce.encode());
+
         // Remove the record
         let record = {
             let mut inner = self.inner.lock();
@@ -378,6 +387,8 @@ impl ReceiptManager {
     }
 
     pub async fn handle_receipt(&self, node_ref: NodeRef, receipt: Receipt) -> Result<(), String> {
+        log_rpc!(debug "<<== RECEIPT {} <- {}", receipt.get_nonce().encode(), node_ref);
+
         // Increment return count
         let callback_future = {
             // Look up the receipt record from the nonce

veilid-core/src/routing_table/bucket_entry.rs

@@ -91,7 +91,8 @@ impl BucketEntry {
         self.node_ref_tracks.remove(&track_id);
     }
 
-    pub fn sort_fastest(e1: &Self, e2: &Self) -> std::cmp::Ordering {
+    // Less is faster
+    pub fn cmp_fastest(e1: &Self, e2: &Self) -> std::cmp::Ordering {
         // Lower latency to the front
         if let Some(e1_latency) = &e1.peer_stats.latency {
             if let Some(e2_latency) = &e2.peer_stats.latency {
@@ -106,6 +107,7 @@ impl BucketEntry {
         }
     }
 
+    // Less is more reliable then faster
     pub fn cmp_fastest_reliable(cur_ts: u64, e1: &Self, e2: &Self) -> std::cmp::Ordering {
         // Reverse compare so most reliable is at front
         let ret = e2.state(cur_ts).cmp(&e1.state(cur_ts));

veilid-core/src/routing_table/mod.rs

@@ -258,11 +258,9 @@ impl RoutingTable {
         dial_info: DialInfo,
         class: DialInfoClass,
     ) -> Result<(), String> {
-        trace!(
+        log_rtab!(debug
-            "registering dial_info with:\n  domain: {:?}\n  dial_info: {:?}\n  class: {:?}",
+            "Registering dial_info with:\n  domain: {:?}\n  dial_info: {:?}\n  class: {:?}",
-            domain,
+            domain, dial_info, class
-            dial_info,
-            class
         );
         let enable_local_peer_scope = {
             let config = self.network_manager().config();
@@ -680,10 +678,13 @@ impl RoutingTable {
 
     pub fn find_inbound_relay(&self, cur_ts: u64) -> Option<NodeRef> {
         let mut inner = self.inner.lock();
-        let mut best_inbound_relay: Option<NodeRef> = None;
+        let inner = &mut *inner;
+        let mut best_inbound_relay: Option<(&DHTKey, &mut BucketEntry)> = None;
 
         // Iterate all known nodes for candidates
-        Self::with_entries(&mut *inner, cur_ts, BucketEntryState::Unreliable, |k, e| {
+        for bucket in &mut inner.buckets {
+            for (k, e) in bucket.entries_mut() {
+                if e.state(cur_ts) >= BucketEntryState::Unreliable {
                     // Ensure this node is not on our local network
                     if !e
                         .local_node_info()
@@ -694,23 +695,29 @@ impl RoutingTable {
                         if let Some(node_status) = &e.peer_stats().status {
                             // Ensure the node will relay
                             if node_status.will_relay {
+                                // Compare against previous candidate
                                 if let Some(best_inbound_relay) = best_inbound_relay.as_mut() {
-                            if best_inbound_relay
+                                    // Less is faster
-                                .operate(|best| BucketEntry::cmp_fastest_reliable(cur_ts, best, e))
+                                    if BucketEntry::cmp_fastest_reliable(
-                                == std::cmp::Ordering::Greater
+                                        cur_ts,
+                                        e,
+                                        best_inbound_relay.1,
+                                    ) == std::cmp::Ordering::Less
                                     {
-                                *best_inbound_relay = NodeRef::new(self.clone(), *k, e, None);
+                                        *best_inbound_relay = (k, e);
                                     }
                                 } else {
-                            best_inbound_relay = Some(NodeRef::new(self.clone(), *k, e, None));
+                                    // Always store the first candidate
+                                    best_inbound_relay = Some((k, e));
                                 }
                             }
                         }
                     }
-            Option::<()>::None
+                }
-        });
+            }
-
+        }
-        best_inbound_relay
+        // Return the best inbound relay noderef
+        best_inbound_relay.map(|(k, e)| NodeRef::new(self.clone(), *k, e, None))
     }
 
     pub fn register_find_node_answer(&self, fna: FindNodeAnswer) -> Result<Vec<NodeRef>, String> {
@@ -920,7 +927,7 @@ impl RoutingTable {
             )
         };
 
-        log_rtab!("--- bootstrap_task");
+        log_rtab!(debug "--- bootstrap_task");
 
         // If we aren't specifying a bootstrap node list explicitly, then pull from the bootstrap server(s)
         let bootstrap_node_dial_infos = if !bootstrap_nodes.is_empty() {
@@ -952,12 +959,11 @@ impl RoutingTable {
                     class: DialInfoClass::Direct, // Bootstraps are always directly reachable
                 });
         }
-        log_rtab!("    bootstrap node dialinfo: {:?}", bsmap);
 
         // Run all bootstrap operations concurrently
         let mut unord = FuturesUnordered::new();
         for (k, v) in bsmap {
-            log_rtab!("    bootstrapping {} with {:?}", k.encode(), &v);
+            log_rtab!("--- bootstrapping {} with {:?}", k.encode(), &v);
 
             // Make invalid signed node info (no signature)
             let nr = self
@@ -970,7 +976,7 @@ impl RoutingTable {
                         relay_peer_info: None,    // Bootstraps never require a relay themselves
                     }),
                 )
-                .map_err(logthru_rtab!("Couldn't add bootstrap node: {}", k))?;
+                .map_err(logthru_rtab!(error "Couldn't add bootstrap node: {}", k))?;
 
             // Add this our futures to process in parallel
             let this = self.clone();
@@ -981,7 +987,7 @@ impl RoutingTable {
 
                 // Ensure we got the signed peer info
                 if !nr.operate(|e| e.has_valid_signed_node_info()) {
-                    warn!(
+                    log_rtab!(warn
                         "bootstrap at {:?} did not return valid signed node info",
                         nr
                     );
@@ -1004,7 +1010,7 @@ impl RoutingTable {
     // Ask our remaining peers to give us more peers before we go
     // back to the bootstrap servers to keep us from bothering them too much
     async fn peer_minimum_refresh_task_routine(self) -> Result<(), String> {
-        log_rtab!("--- peer_minimum_refresh task");
+        // log_rtab!("--- peer_minimum_refresh task");
 
         // get list of all peers we know about, even the unreliable ones, and ask them to find nodes close to our node too
         let noderefs = {
@@ -1022,12 +1028,11 @@ impl RoutingTable {
             );
             noderefs
         };
-        log_rtab!("    refreshing with nodes: {:?}", noderefs);
 
         // do peer minimum search concurrently
         let mut unord = FuturesUnordered::new();
         for nr in noderefs {
-            debug!("    --- peer minimum search with {:?}", nr);
+            log_rtab!("--- peer minimum search with {:?}", nr);
             unord.push(self.reverse_find_node(nr, false));
         }
         while unord.next().await.is_some() {}

veilid-core/src/rpc_processor/mod.rs

@@ -78,7 +78,7 @@ impl RespondTo {
 
 #[derive(Debug, Clone)]
 struct RPCMessageHeader {
-    timestamp: u64,
+    timestamp: u64,             // time the message was received, not sent
     envelope: envelope::Envelope,
     body_len: u64,
     peer_noderef: NodeRef, // ensures node doesn't get evicted from routing table until we're done with it
@@ -911,6 +911,7 @@ impl RPCProcessor {
         if redirect {
             let routing_table = self.routing_table();
             let filter = dial_info.make_filter(true);
+            let sender_id = rpcreader.header.envelope.get_sender_id();
             let peers = routing_table.find_fast_public_nodes_filtered(&filter);
             if peers.is_empty() {
                 return Err(rpc_error_internal(format!(
@@ -919,6 +920,12 @@ impl RPCProcessor {
                 )));
             }
             for peer in peers {
+
+                // Ensure the peer is not the one asking for the validation
+                if peer.node_id() == sender_id {
+                    continue;
+                }                
+
                 // See if this peer will validate dial info
                 let will_validate_dial_info = peer.operate(|e: &mut BucketEntry| {
                     if let Some(ni) = &e.peer_stats().status {
@@ -1259,7 +1266,7 @@ impl RPCProcessor {
                 veilid_capnp::operation::detail::CancelTunnelA(_) => (25u32, false),
             };
 
-            log_rpc!(debug "<<== {}({}) <- {}", 
+            log_rpc!(debug "<<== {}({}) <- {:?}", 
                 if is_q { "REQUEST" } else { "REPLY" }, 
                 self.get_rpc_message_debug_info(&reader), 
                 msg.header.envelope.get_sender_id()
@@ -1604,10 +1611,17 @@ impl RPCProcessor {
         self.request(Destination::Direct(peer), vdi_msg, None)
             .await?;
 
+        log_net!(debug "waiting for validate_dial_info receipt");
         // Wait for receipt
         match eventual_value.await.take_value().unwrap() {
-            ReceiptEvent::Returned(_) => Ok(true),
+            ReceiptEvent::Returned(_) => {
-            ReceiptEvent::Expired => Ok(false),
+                log_net!(debug "validate_dial_info receipt returned");
+                Ok(true)
+            }
+            ReceiptEvent::Expired => {
+                log_net!(debug "validate_dial_info receipt expired");
+                Ok(false)
+            }
             ReceiptEvent::Cancelled => {
                 Err(rpc_error_internal("receipt was dropped before expiration"))
             }

veilid-core/src/xx/tools.rs

@@ -63,15 +63,7 @@ pub fn retry_falloff_log(
         true
     } else {
         // Exponential falloff between 'interval_start_us' and 'interval_max_us' microseconds
-        // Optimal equation here is: y = Sum[Power[b,x],{n,0,x}] --> y = (x+1)b^x
+        last_us <= secs_to_timestamp(timestamp_to_secs(cur_us) / interval_multiplier_us)
-        // but we're just gonna simplify this to a log curve for speed
-        let last_secs = timestamp_to_secs(last_us);
-        let nth = (last_secs / timestamp_to_secs(interval_start_us))
-            .log(interval_multiplier_us)
-            .floor() as i32;
-        let next_secs = timestamp_to_secs(interval_start_us) * interval_multiplier_us.powi(nth + 1);
-        let next_us = secs_to_timestamp(next_secs);
-        cur_us >= next_us
     }
 }
 

veilid-server/src/settings.rs

@@ -1186,6 +1186,8 @@ mod tests {
             listen_address_to_socket_addrs("localhost:5959").unwrap()
         );
         assert_eq!(s.auto_attach, true);
+        assert_eq!(s.logging.system.enabled, false);
+        assert_eq!(s.logging.system.level, LogLevel::Info);
         assert_eq!(s.logging.terminal.enabled, true);
         assert_eq!(s.logging.terminal.level, LogLevel::Info);
         assert_eq!(s.logging.file.enabled, false);