diff --git a/Cargo.lock b/Cargo.lock index 3c0b0907..5aeab7b8 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -6469,7 +6469,6 @@ dependencies = [ "nix 0.26.2", "once_cell", "owning_ref", - "owo-colors", "paranoid-android", "parking_lot 0.12.1", "paste", @@ -6623,7 +6622,6 @@ dependencies = [ "nix 0.26.2", "once_cell", "oslog", - "owo-colors", "paranoid-android", "parking_lot 0.11.2", "rand 0.7.3", diff --git a/veilid-core/Cargo.toml b/veilid-core/Cargo.toml index 6b6e95f6..338c8555 100644 --- a/veilid-core/Cargo.toml +++ b/veilid-core/Cargo.toml @@ -23,6 +23,7 @@ rt-wasm-bindgen = ["veilid-tools/rt-wasm-bindgen", "async_executors/bindgen"] veilid_core_android_tests = ["dep:paranoid-android"] veilid_core_ios_tests = ["dep:tracing-oslog"] tracking = [] +network-result-extra = ["veilid-tools/network-result-extra"] [dependencies] veilid-tools = { path = "../veilid-tools", features = [ "tracing" ] } @@ -53,7 +54,6 @@ owning_ref = "^0" flume = { version = "^0", features = ["async"] } enumset = { version= "^1", features = ["serde"] } backtrace = { version = "^0" } -owo-colors = "^3" stop-token = { version = "^0", default-features = false } ed25519-dalek = { version = "^1", default_features = false, features = ["alloc", "u64_backend"] } diff --git a/veilid-core/src/lib.rs b/veilid-core/src/lib.rs index f49417d9..ef3bdeb9 100644 --- a/veilid-core/src/lib.rs +++ b/veilid-core/src/lib.rs @@ -97,7 +97,6 @@ use tracing::*; use veilid_tools::*; type RkyvDefaultValidator<'t> = rkyv::validation::validators::DefaultValidator<'t>; use futures_util::stream::FuturesUnordered; -use owo_colors::OwoColorize; use schemars::{schema_for, JsonSchema}; use serde::*; use stop_token::*; diff --git a/veilid-core/src/network_manager/connection_manager.rs b/veilid-core/src/network_manager/connection_manager.rs index 342925c9..1d1445d5 100644 --- a/veilid-core/src/network_manager/connection_manager.rs +++ b/veilid-core/src/network_manager/connection_manager.rs @@ -256,8 +256,8 @@ impl ConnectionManager { log_net!( "== get_or_create_connection local_addr={:?} dial_info={:?}", - local_addr.green(), - dial_info.green() + local_addr, + dial_info ); // Kill off any possibly conflicting connections @@ -273,8 +273,8 @@ impl ConnectionManager { { log_net!( "== Returning existing connection local_addr={:?} peer_address={:?}", - local_addr.green(), - peer_address.green() + local_addr, + peer_address ); return Ok(NetworkResult::Value(conn)); @@ -300,8 +300,8 @@ impl ConnectionManager { { log_net!( "== Returning existing connection in race local_addr={:?} peer_address={:?}", - local_addr.green(), - peer_address.green() + local_addr, + peer_address ); return Ok(NetworkResult::Value(conn)); diff --git a/veilid-core/src/network_manager/direct_boot.rs b/veilid-core/src/network_manager/direct_boot.rs index 3f6c74ad..d739c54d 100644 --- a/veilid-core/src/network_manager/direct_boot.rs +++ b/veilid-core/src/network_manager/direct_boot.rs @@ -45,7 +45,7 @@ impl NetworkManager { let out_data: Vec = network_result_value_or_log!(self .net() .send_recv_data_unbound_to_dial_info(dial_info, data, timeout_ms) - .await? => + .await? => [ format!(": dial_info={}, data.len={}", dial_info, data.len()) ] { return Ok(Vec::new()); }); diff --git a/veilid-core/src/network_manager/mod.rs b/veilid-core/src/network_manager/mod.rs index 01ab901e..778dbe40 100644 --- a/veilid-core/src/network_manager/mod.rs +++ b/veilid-core/src/network_manager/mod.rs @@ -845,7 +845,7 @@ impl NetworkManager { } /// Called by the RPC handler when we want to issue an direct receipt - #[instrument(level = "trace", skip(self, rcpt_data), err)] + #[instrument(level = "debug", skip(self, rcpt_data), err)] pub async fn send_out_of_band_receipt( &self, dial_info: DialInfo, @@ -858,11 +858,10 @@ impl NetworkManager { // should not be subject to our ability to decode it // Send receipt directly - log_net!(debug "send_out_of_band_receipt: dial_info={}", dial_info); network_result_value_or_log!(self .net() .send_data_unbound_to_dial_info(dial_info, rcpt_data) - .await? => { + .await? => [ format!(": dial_info={}, rcpt_data.len={}", dial_info, rcpt_data.len()) ] { return Ok(()); } ); @@ -928,13 +927,13 @@ impl NetworkManager { // Is this a direct bootstrap request instead of an envelope? if data[0..4] == *BOOT_MAGIC { - network_result_value_or_log!(self.handle_boot_request(connection_descriptor).await? => {}); + network_result_value_or_log!(self.handle_boot_request(connection_descriptor).await? => [ format!(": connection_descriptor={:?}", connection_descriptor) ] {}); return Ok(true); } // Is this an out-of-band receipt instead of an envelope? if data[0..3] == *RECEIPT_MAGIC { - network_result_value_or_log!(self.handle_out_of_band_receipt(data).await => {}); + network_result_value_or_log!(self.handle_out_of_band_receipt(data).await => [ format!(": data.len={}", data.len()) ] {}); return Ok(true); } @@ -1040,7 +1039,7 @@ impl NetworkManager { log_net!(debug "failed to forward envelope: {}" ,e); return Ok(false); } - } => { + } => [ format!(": relay_nr={}, data.len={}", relay_nr, data.len()) ] { return Ok(false); } ); diff --git a/veilid-core/src/network_manager/native/mod.rs b/veilid-core/src/network_manager/native/mod.rs index 9dadc845..8a3a7023 100644 --- a/veilid-core/src/network_manager/native/mod.rs +++ b/veilid-core/src/network_manager/native/mod.rs @@ -515,7 +515,8 @@ impl Network { network_result_value_or_log!(ph.clone() .send_message(data.clone(), peer_socket_addr) .await - .wrap_err("sending data to existing conection")? => { return Ok(Some(data)); } ); + .wrap_err("sending data to existing conection")? => [ format!(": data.len={}, descriptor={:?}", data.len(), descriptor) ] + { return Ok(Some(data)); } ); // Network accounting self.network_manager() diff --git a/veilid-core/src/network_manager/native/network_class_discovery.rs b/veilid-core/src/network_manager/native/network_class_discovery.rs index 0d7de718..01dbde9d 100644 --- a/veilid-core/src/network_manager/native/network_class_discovery.rs +++ b/veilid-core/src/network_manager/native/network_class_discovery.rs @@ -92,7 +92,7 @@ impl DiscoveryContext { ); return None; } - } => { + } => [ format!(": node_ref={}", node_ref) ] { return None; } ); diff --git a/veilid-core/src/network_manager/native/protocol/udp.rs b/veilid-core/src/network_manager/native/protocol/udp.rs index f5989e2a..a8d33b5a 100644 --- a/veilid-core/src/network_manager/native/protocol/udp.rs +++ b/veilid-core/src/network_manager/native/protocol/udp.rs @@ -28,7 +28,7 @@ impl RawUdpProtocolHandler { // Check length of reassembled message (same for all protocols) if message.len() > MAX_MESSAGE_SIZE { - log_net!(debug "{}({}) at {}@{}:{}", "Invalid message".green(), "received too large UDP message", file!(), line!(), column!()); + log_net!(debug "{}({}) at {}@{}:{}", "Invalid message", "received too large UDP message", file!(), line!(), column!()); continue; } diff --git a/veilid-core/src/network_manager/network_connection.rs b/veilid-core/src/network_manager/network_connection.rs index b01a7aea..333ae677 100644 --- a/veilid-core/src/network_manager/network_connection.rs +++ b/veilid-core/src/network_manager/network_connection.rs @@ -236,7 +236,7 @@ impl NetworkConnection { Box::pin(async move { log_net!( "== Starting process_connection loop for id={}, {:?}", connection_id, - descriptor.green() + descriptor ); let network_manager = connection_manager.network_manager(); @@ -249,7 +249,7 @@ impl NetworkConnection { let new_timer = || { sleep(connection_manager.connection_inactivity_timeout_ms()).then(|_| async { // timeout - log_net!("== Connection timeout on {:?}", descriptor.green()); + log_net!("== Connection timeout on {:?}", descriptor); RecvLoopAction::Timeout }) }; @@ -306,7 +306,7 @@ impl NetworkConnection { log_net!(debug "Connection closed from: {} ({})", peer_address.socket_address().to_socket_addr(), peer_address.protocol_type()); return RecvLoopAction::Finish; } - let mut message = network_result_value_or_log!(v => { + let mut message = network_result_value_or_log!(v => [ format!(": protocol_connection={:?}", protocol_connection) ] { return RecvLoopAction::Finish; }); @@ -366,7 +366,7 @@ impl NetworkConnection { log_net!( "== Connection loop finished descriptor={:?}", - descriptor.green() + descriptor ); // Let the connection manager know the receive loop exited diff --git a/veilid-core/src/network_manager/types/dial_info/tcp.rs b/veilid-core/src/network_manager/types/dial_info/tcp.rs index 0f93273d..ce7de8b4 100644 --- a/veilid-core/src/network_manager/types/dial_info/tcp.rs +++ b/veilid-core/src/network_manager/types/dial_info/tcp.rs @@ -18,4 +18,4 @@ use super::*; #[archive_attr(repr(C), derive(CheckBytes))] pub struct DialInfoTCP { pub socket_address: SocketAddress, -} \ No newline at end of file +} diff --git a/veilid-core/src/routing_table/mod.rs b/veilid-core/src/routing_table/mod.rs index 81a2dbd7..91143fb3 100644 --- a/veilid-core/src/routing_table/mod.rs +++ b/veilid-core/src/routing_table/mod.rs @@ -1121,7 +1121,7 @@ impl RoutingTable { return; } Ok(v) => v, - } => { + } => [ format!(": crypto_kind={} node_ref={} wide={}", crypto_kind, node_ref, wide) ] { return; }); @@ -1137,7 +1137,7 @@ impl RoutingTable { continue; } Ok(v) => v, - } => { + } => [ format!(": crypto_kind={} closest_nr={} wide={}", crypto_kind, closest_nr, wide) ] { // Do nothing with non-values continue; }); diff --git a/veilid-core/src/rpc_processor/coders/operations/operation_route.rs b/veilid-core/src/rpc_processor/coders/operations/operation_route.rs index 7d72bd4c..38a7c3a1 100644 --- a/veilid-core/src/rpc_processor/coders/operations/operation_route.rs +++ b/veilid-core/src/rpc_processor/coders/operations/operation_route.rs @@ -1,6 +1,6 @@ use super::*; -#[derive(Debug, Clone)] +#[derive(Clone)] pub struct RoutedOperation { sequencing: Sequencing, signatures: Vec, @@ -8,6 +8,17 @@ pub struct RoutedOperation { data: Vec, } +impl fmt::Debug for RoutedOperation { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + f.debug_struct("RoutedOperation") + .field("sequencing", &self.sequencing) + .field("signatures.len", &self.signatures.len()) + .field("nonce", &self.nonce) + .field("data(len)", &self.data.len()) + .finish() + } +} + impl RoutedOperation { pub fn new(sequencing: Sequencing, nonce: Nonce, data: Vec) -> Self { Self { diff --git a/veilid-core/src/rpc_processor/mod.rs b/veilid-core/src/rpc_processor/mod.rs index cf71b849..02f1d140 100644 --- a/veilid-core/src/rpc_processor/mod.rs +++ b/veilid-core/src/rpc_processor/mod.rs @@ -182,7 +182,7 @@ impl Answer { } } -/// An operation that has been fully prepared for envelope r +/// An operation that has been fully prepared for envelope struct RenderedOperation { /// The rendered operation bytes message: Vec, @@ -200,6 +200,20 @@ struct RenderedOperation { reply_private_route: Option, } +impl fmt::Debug for RenderedOperation { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + f.debug_struct("RenderedOperation") + .field("message(len)", &self.message.len()) + .field("destination_node_ref", &self.destination_node_ref) + .field("node_ref", &self.node_ref) + .field("hop_count", &self.hop_count) + .field("safety_route", &self.safety_route) + .field("remote_private_route", &self.remote_private_route) + .field("reply_private_route", &self.reply_private_route) + .finish() + } +} + /// Node information exchanged during every RPC message #[derive(Default, Debug, Clone)] pub struct SenderPeerInfo { @@ -431,7 +445,7 @@ impl RPCProcessor { .await { Ok(v) => { - let v = network_result_value_or_log!(v => { + let v = network_result_value_or_log!(v => [ format!(": node_id={} count={} fanout={} fanout={} safety_selection={:?}", node_id, count, fanout, timeout_us, safety_selection) ] { // Any other failures, just try the next node return Ok(None); }); @@ -541,8 +555,7 @@ impl RPCProcessor { .await; match &out { Err(e) => { - let msg = format!("RPC Lost ({}): {}", debug_string, e); - log_rpc!(debug "{}", msg.bright_magenta()); + log_rpc!(debug "RPC Lost ({}): {}", debug_string, e); self.record_question_lost( waitable_reply.send_ts, waitable_reply.node_ref.clone(), @@ -552,8 +565,7 @@ impl RPCProcessor { ); } Ok(TimeoutOr::Timeout) => { - let msg = format!("RPC Lost ({}): Timeout", debug_string); - log_rpc!(debug "{}", msg.bright_cyan()); + log_rpc!(debug "RPC Lost ({}): Timeout", debug_string); self.record_question_lost( waitable_reply.send_ts, waitable_reply.node_ref.clone(), @@ -1148,17 +1160,31 @@ impl RPCProcessor { // Send question let bytes: ByteCount = (message.len() as u64).into(); let send_ts = get_aligned_timestamp(); - let send_data_kind = network_result_try!(self + #[allow(unused_variables)] + let message_len = message.len(); + let res = self .network_manager() - .send_envelope(node_ref.clone(), Some(destination_node_ref), message) + .send_envelope( + node_ref.clone(), + Some(destination_node_ref.clone()), + message, + ) .await .map_err(|e| { // If we're returning an error, clean up - self.record_send_failure(RPCKind::Question, send_ts, node_ref.clone(), safety_route, remote_private_route); + self.record_send_failure( + RPCKind::Question, + send_ts, + node_ref.clone(), + safety_route, + remote_private_route, + ); RPCError::network(e) - })? => { + })?; + let send_data_kind = network_result_value_or_log!( res => [ format!(": node_ref={}, destination_node_ref={}, message.len={}", node_ref, destination_node_ref, message_len) ] { // If we couldn't send we're still cleaning up self.record_send_failure(RPCKind::Question, send_ts, node_ref.clone(), safety_route, remote_private_route); + network_result_raise!(res); } ); @@ -1218,17 +1244,31 @@ impl RPCProcessor { // Send statement let bytes: ByteCount = (message.len() as u64).into(); let send_ts = get_aligned_timestamp(); - let _send_data_kind = network_result_try!(self + #[allow(unused_variables)] + let message_len = message.len(); + let res = self .network_manager() - .send_envelope(node_ref.clone(), Some(destination_node_ref), message) + .send_envelope( + node_ref.clone(), + Some(destination_node_ref.clone()), + message, + ) .await .map_err(|e| { // If we're returning an error, clean up - self.record_send_failure(RPCKind::Statement, send_ts, node_ref.clone(), safety_route, remote_private_route); + self.record_send_failure( + RPCKind::Statement, + send_ts, + node_ref.clone(), + safety_route, + remote_private_route, + ); RPCError::network(e) - })? => { + })?; + let _send_data_kind = network_result_value_or_log!( res => [ format!(": node_ref={}, destination_node_ref={}, message.len={}", node_ref, destination_node_ref, message_len) ] { // If we couldn't send we're still cleaning up self.record_send_failure(RPCKind::Statement, send_ts, node_ref.clone(), safety_route, remote_private_route); + network_result_raise!(res); } ); @@ -1281,16 +1321,31 @@ impl RPCProcessor { // Send the reply let bytes: ByteCount = (message.len() as u64).into(); let send_ts = get_aligned_timestamp(); - network_result_try!(self.network_manager() - .send_envelope(node_ref.clone(), Some(destination_node_ref), message) + #[allow(unused_variables)] + let message_len = message.len(); + let res = self + .network_manager() + .send_envelope( + node_ref.clone(), + Some(destination_node_ref.clone()), + message, + ) .await .map_err(|e| { // If we're returning an error, clean up - self.record_send_failure(RPCKind::Answer, send_ts, node_ref.clone(), safety_route, remote_private_route); + self.record_send_failure( + RPCKind::Answer, + send_ts, + node_ref.clone(), + safety_route, + remote_private_route, + ); RPCError::network(e) - })? => { + })?; + let _send_data_kind = network_result_value_or_log!( res => [ format!(": node_ref={}, destination_node_ref={}, message.len={}", node_ref, destination_node_ref, message_len) ] { // If we couldn't send we're still cleaning up self.record_send_failure(RPCKind::Answer, send_ts, node_ref.clone(), safety_route, remote_private_route); + network_result_raise!(res); } ); @@ -1513,7 +1568,8 @@ impl RPCProcessor { let rpc_worker_span = span!(parent: None, Level::TRACE, "rpc_worker recv"); // xxx: causes crash (Missing otel data span extensions) // rpc_worker_span.follows_from(span_id); - let res = match self + + network_result_value_or_log!(match self .process_rpc_message(msg) .instrument(rpc_worker_span) .await @@ -1524,9 +1580,7 @@ impl RPCProcessor { } Ok(v) => v, - }; - - network_result_value_or_log!(res => {}); + } => [ format!(": msg.header={:?}", msg.header) ] {}); } } @@ -1542,19 +1596,22 @@ impl RPCProcessor { routing_domain: RoutingDomain, body: Vec, ) -> EyreResult<()> { + let header = RPCMessageHeader { + detail: RPCMessageHeaderDetail::Direct(RPCMessageHeaderDetailDirect { + envelope, + peer_noderef, + connection_descriptor, + routing_domain, + }), + timestamp: get_aligned_timestamp(), + body_len: ByteCount::new(body.len() as u64), + }; + let msg = RPCMessageEncoded { - header: RPCMessageHeader { - detail: RPCMessageHeaderDetail::Direct(RPCMessageHeaderDetailDirect { - envelope, - peer_noderef, - connection_descriptor, - routing_domain, - }), - timestamp: get_aligned_timestamp(), - body_len: ByteCount::new(body.len() as u64), - }, + header, data: RPCMessageData { contents: body }, }; + let send_channel = { let inner = self.inner.lock(); inner.send_channel.as_ref().unwrap().clone() @@ -1577,16 +1634,18 @@ impl RPCProcessor { sequencing: Sequencing, body: Vec, ) -> EyreResult<()> { + let header = RPCMessageHeader { + detail: RPCMessageHeaderDetail::SafetyRouted(RPCMessageHeaderDetailSafetyRouted { + direct, + remote_safety_route, + sequencing, + }), + timestamp: get_aligned_timestamp(), + body_len: (body.len() as u64).into(), + }; + let msg = RPCMessageEncoded { - header: RPCMessageHeader { - detail: RPCMessageHeaderDetail::SafetyRouted(RPCMessageHeaderDetailSafetyRouted { - direct, - remote_safety_route, - sequencing, - }), - timestamp: get_aligned_timestamp(), - body_len: (body.len() as u64).into(), - }, + header, data: RPCMessageData { contents: body }, }; let send_channel = { @@ -1612,21 +1671,22 @@ impl RPCProcessor { safety_spec: SafetySpec, body: Vec, ) -> EyreResult<()> { + let header = RPCMessageHeader { + detail: RPCMessageHeaderDetail::PrivateRouted(RPCMessageHeaderDetailPrivateRouted { + direct, + remote_safety_route, + private_route, + safety_spec, + }), + timestamp: get_aligned_timestamp(), + body_len: (body.len() as u64).into(), + }; + let msg = RPCMessageEncoded { - header: RPCMessageHeader { - detail: RPCMessageHeaderDetail::PrivateRouted( - RPCMessageHeaderDetailPrivateRouted { - direct, - remote_safety_route, - private_route, - safety_spec, - }, - ), - timestamp: get_aligned_timestamp(), - body_len: (body.len() as u64).into(), - }, + header, data: RPCMessageData { contents: body }, }; + let send_channel = { let inner = self.inner.lock(); inner.send_channel.as_ref().unwrap().clone() diff --git a/veilid-core/src/rpc_processor/rpc_route.rs b/veilid-core/src/rpc_processor/rpc_route.rs index 8694c3d9..7e45bccd 100644 --- a/veilid-core/src/rpc_processor/rpc_route.rs +++ b/veilid-core/src/rpc_processor/rpc_route.rs @@ -360,7 +360,7 @@ impl RPCProcessor { Ok(NetworkResult::value(route_hop)) } - #[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), ret, err))] + #[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self), ret, err))] pub(crate) async fn process_route( &self, msg: RPCMessage, diff --git a/veilid-core/src/rpc_processor/rpc_validate_dial_info.rs b/veilid-core/src/rpc_processor/rpc_validate_dial_info.rs index c1a70039..2ff38e4e 100644 --- a/veilid-core/src/rpc_processor/rpc_validate_dial_info.rs +++ b/veilid-core/src/rpc_processor/rpc_validate_dial_info.rs @@ -26,7 +26,7 @@ impl RPCProcessor { // Send the validate_dial_info request // This can only be sent directly, as relays can not validate dial info network_result_value_or_log!(self.statement(Destination::direct(peer), statement) - .await? => { + .await? => [ format!(": peer={} statement={:?}", peer, statement) ] { return Ok(false); } ); @@ -36,7 +36,7 @@ impl RPCProcessor { ReceiptEvent::ReturnedPrivate { private_route: _ } | ReceiptEvent::ReturnedInBand { inbound_noderef: _ } | ReceiptEvent::ReturnedSafety => { - log_net!(debug "validate_dial_info receipt should be returned out-of-band".green()); + log_net!(debug "validate_dial_info receipt should be returned out-of-band"); Ok(false) } ReceiptEvent::ReturnedOutOfBand => { @@ -44,7 +44,7 @@ impl RPCProcessor { Ok(true) } ReceiptEvent::Expired => { - log_net!(debug "validate_dial_info receipt expired".green()); + log_net!(debug "validate_dial_info receipt expired"); Ok(false) } ReceiptEvent::Cancelled => { @@ -141,7 +141,7 @@ impl RPCProcessor { // Send the validate_dial_info request // This can only be sent directly, as relays can not validate dial info network_result_value_or_log!(self.statement(Destination::direct(peer), statement) - .await? => { + .await? => [ format!(": peer={} statement={:?}", peer, statement) ] { continue; } ); diff --git a/veilid-core/src/storage_manager/get_value.rs b/veilid-core/src/storage_manager/get_value.rs index b05e4de5..b2a34303 100644 --- a/veilid-core/src/storage_manager/get_value.rs +++ b/veilid-core/src/storage_manager/get_value.rs @@ -58,13 +58,13 @@ impl StorageManager { let vres = rpc_processor .clone() .rpc_call_get_value( - Destination::direct(next_node).with_safety(safety_selection), + Destination::direct(next_node.clone()).with_safety(safety_selection), key, subkey, last_descriptor, ) .await?; - let gva = network_result_value_or_log!(vres => { + let gva = network_result_value_or_log!(vres => [ format!(": next_node={} safety_selection={:?} key={} subkey={}", next_node, safety_selection, key, subkey) ] { // Any other failures, just try the next node return Ok(None); }); diff --git a/veilid-core/src/storage_manager/set_value.rs b/veilid-core/src/storage_manager/set_value.rs index 0d79dfe1..5222f89a 100644 --- a/veilid-core/src/storage_manager/set_value.rs +++ b/veilid-core/src/storage_manager/set_value.rs @@ -62,7 +62,7 @@ impl StorageManager { let vres = rpc_processor .clone() .rpc_call_set_value( - Destination::direct(next_node).with_safety(safety_selection), + Destination::direct(next_node.clone()).with_safety(safety_selection), key, subkey, value, @@ -70,7 +70,7 @@ impl StorageManager { send_descriptor, ) .await?; - let sva = network_result_value_or_log!(vres => { + let sva = network_result_value_or_log!(vres => [ format!(": next_node={} safety_selection={:?} key={} subkey={} send_descriptor={}", next_node, safety_selection, key, subkey, send_descriptor) ] { // Any other failures, just try the next node and pretend this one never happened return Ok(None); }); diff --git a/veilid-server/Cargo.toml b/veilid-server/Cargo.toml index 11317371..a2193b74 100644 --- a/veilid-server/Cargo.toml +++ b/veilid-server/Cargo.toml @@ -17,6 +17,7 @@ crypto-test-none = ["rt-tokio", "veilid-core/crypto-test-none"] rt-async-std = ["veilid-core/rt-async-std", "async-std", "opentelemetry/rt-async-std", "opentelemetry-otlp/grpc-sys"] rt-tokio = ["veilid-core/rt-tokio", "tokio", "tokio-stream", "tokio-util", "opentelemetry/rt-tokio", "console-subscriber"] tracking = ["veilid-core/tracking"] +network-result-extra = ["veilid-core/network-result-extra"] [dependencies] veilid-core = { path = "../veilid-core", default-features = false } diff --git a/veilid-tools/Cargo.toml b/veilid-tools/Cargo.toml index f92d6ad2..51717ee2 100644 --- a/veilid-tools/Cargo.toml +++ b/veilid-tools/Cargo.toml @@ -18,6 +18,8 @@ rt-wasm-bindgen = [ "async_executors/bindgen", "async_executors/timer"] veilid_tools_android_tests = [ "dep:paranoid-android" ] veilid_tools_ios_tests = [ "dep:oslog", "dep:tracing-oslog" ] tracing = [ "dep:tracing", "dep:tracing-subscriber" ] +network-result-extra = [] +network-result-info = [] [dependencies] tracing = { version = "^0", features = ["log", "attributes"], optional = true } @@ -30,7 +32,6 @@ thiserror = "^1" futures-util = { version = "^0", default_features = false, features = ["alloc"] } parking_lot = "^0" once_cell = "^1" -owo-colors = "^3" stop-token = { version = "^0", default-features = false } rand = "^0.7" rust-fsm = "^0" diff --git a/veilid-tools/src/network_result.rs b/veilid-tools/src/network_result.rs index e73a0599..905a8b5f 100644 --- a/veilid-tools/src/network_result.rs +++ b/veilid-tools/src/network_result.rs @@ -271,6 +271,20 @@ impl Error for NetworkResult {} ////////////////////////////////////////////////////////////////// // Non-fallible network result macros +#[macro_export] +macro_rules! network_result_raise { + ($r: expr) => { + match $r { + NetworkResult::Timeout => return Ok(NetworkResult::Timeout), + 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)), + NetworkResult::Value(_) => panic!("Can not raise value"), + } + }; +} + #[macro_export] macro_rules! network_result_try { ($r: expr) => { @@ -313,89 +327,102 @@ 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 { - debug!(target: "network_result", "{}", $text) - // } - // } + cfg_if::cfg_if! { + if #[cfg(feature="network-result-info")] { + info!(target: "network_result", "{}", format!("{}", $text)) + } else { + debug!(target: "network_result", "{}", format!("{}", $text)) + } + } }; ($fmt:literal, $($arg:expr),+) => { - // cfg_if::cfg_if! { - // if #[cfg(debug_assertions)] { - // info!(target: "network_result", $fmt, $($arg),+); - // } else { - debug!(target: "network_result", $fmt, $($arg),+); - // } - // } + cfg_if::cfg_if! { + if #[cfg(feature="network-result-info")] { + info!(target: "network_result", "{}", format!($fmt, $($arg),+)); + } else { + debug!(target: "network_result", "{}", format!($fmt, $($arg),+)); + } + } }; } #[macro_export] macro_rules! network_result_value_or_log { - ($r: expr => $f:tt) => { + ($r:expr => $f:expr) => { + network_result_value_or_log!($r => [ "" ] $f ) + }; + ($r:expr => [ $d:expr ] $f:expr) => { { + #[cfg(feature="network-result-extra")] + let __extra_message = $d; + #[cfg(not(feature="network-result-extra"))] + let __extra_message = ""; match $r { NetworkResult::Timeout => { log_network_result!( - "{} at {}@{}:{} in {}", + "{} at {}@{}:{} in {}{}", "Timeout", file!(), line!(), column!(), - fn_name::uninstantiated!() + fn_name::uninstantiated!(), + __extra_message ); $f } - NetworkResult::ServiceUnavailable(s) => { + NetworkResult::ServiceUnavailable(ref s) => { log_network_result!( - "{}({}) at {}@{}:{} in {}", + "{}({}) at {}@{}:{} in {}{}", "ServiceUnavailable", s, file!(), line!(), column!(), - fn_name::uninstantiated!() + fn_name::uninstantiated!(), + __extra_message ); $f } - NetworkResult::NoConnection(e) => { + NetworkResult::NoConnection(ref e) => { log_network_result!( - "{}({}) at {}@{}:{} in {}", + "{}({}) at {}@{}:{} in {}{}", "No connection", e.to_string(), file!(), line!(), column!(), - fn_name::uninstantiated!() + fn_name::uninstantiated!(), + __extra_message ); $f } - NetworkResult::AlreadyExists(e) => { + NetworkResult::AlreadyExists(ref e) => { log_network_result!( - "{}({}) at {}@{}:{} in {}", + "{}({}) at {}@{}:{} in {}{}", "Already exists", e.to_string(), file!(), line!(), column!(), - fn_name::uninstantiated!() + fn_name::uninstantiated!(), + __extra_message ); $f } - NetworkResult::InvalidMessage(s) => { + NetworkResult::InvalidMessage(ref s) => { log_network_result!( - "{}({}) at {}@{}:{} in {}", + "{}({}) at {}@{}:{} in {}{}", "Invalid message", s, file!(), line!(), column!(), - fn_name::uninstantiated!() + fn_name::uninstantiated!(), + __extra_message ); $f } NetworkResult::Value(v) => v, } - }; + } }; + }