liz/veilid
1
0
Fork 0
Code Pull Requests Packages Releases Activity

simplify tracing

Browse Source
This commit is contained in:
John Smith
2023-06-24 22:59:51 -04:00
parent c8fdded5a7
commit 234f048241
38 changed files with 197 additions and 114 deletions
Download Patch File Download Diff File Expand all files Collapse all files
veilid-core/src/rpc_processor/mod.rs
+40 -10
View File
@@ -525,7 +525,10 @@ impl RPCProcessor {
})
}
#[instrument(level = "trace", skip(self, waitable_reply), err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self, waitable_reply), err)
)]
async fn wait_for_reply(
&self,
waitable_reply: WaitableReply,
@@ -662,7 +665,10 @@ impl RPCProcessor {
/// Produce a byte buffer that represents the wire encoding of the entire
/// unencrypted envelope body for a RPC message. This incorporates
/// wrapping a private and/or safety route if they are specified.
#[instrument(level = "debug", skip(self, operation), err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "debug", skip(self, operation), err)
)]
fn render_operation(
&self,
dest: Destination,
@@ -790,7 +796,10 @@ impl RPCProcessor {
/// routing table caching when it is okay to do so
/// Also check target's timestamp of our own node info, to see if we should send that
/// And send our timestamp of the target's node info so they can determine if they should update us on their next rpc
#[instrument(level = "trace", skip(self), ret)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self), ret)
)]
fn get_sender_peer_info(&self, dest: &Destination) -> SenderPeerInfo {
// Don't do this if the sender is to remain private
// Otherwise we would be attaching the original sender's identity to the final destination,
@@ -1091,7 +1100,10 @@ impl RPCProcessor {
/// Issue a question over the network, possibly using an anonymized route
/// Optionally keeps a context to be passed to the answer processor when an answer is received
#[instrument(level = "debug", skip(self, question), err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "debug", skip(self, question), err)
)]
async fn question(
&self,
dest: Destination,
@@ -1170,7 +1182,10 @@ impl RPCProcessor {
}
/// Issue a statement over the network, possibly using an anonymized route
#[instrument(level = "debug", skip(self, statement), err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "debug", skip(self, statement), err)
)]
async fn statement(
&self,
dest: Destination,
@@ -1227,7 +1242,10 @@ impl RPCProcessor {
}
/// Issue a reply over the network, possibly using an anonymized route
/// The request must want a response, or this routine fails
#[instrument(level = "debug", skip(self, request, answer), err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "debug", skip(self, request, answer), err)
)]
async fn answer(
&self,
request: RPCMessage,
@@ -1335,7 +1353,10 @@ impl RPCProcessor {
}
//////////////////////////////////////////////////////////////////////
#[instrument(level = "trace", skip(self, encoded_msg), err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self, encoded_msg), err)
)]
async fn process_rpc_message(
&self,
encoded_msg: RPCMessageEncoded,
@@ -1505,7 +1526,10 @@ impl RPCProcessor {
}
}
#[instrument(level = "trace", skip(self, body), err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self, body), err)
)]
pub fn enqueue_direct_message(
&self,
envelope: Envelope,
@@ -1538,7 +1562,10 @@ impl RPCProcessor {
Ok(())
}
#[instrument(level = "trace", skip(self, body), err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self, body), err)
)]
fn enqueue_safety_routed_message(
&self,
direct: RPCMessageHeaderDetailDirect,
@@ -1569,7 +1596,10 @@ impl RPCProcessor {
Ok(())
}
#[instrument(level = "trace", skip(self, body), err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self, body), err)
)]
fn enqueue_private_routed_message(
&self,
direct: RPCMessageHeaderDetailDirect,
veilid-core/src/rpc_processor/operation_waiter.rs
+4 -1
View File
@@ -114,7 +114,10 @@ where
}
/// Complete the app call
#[instrument(level = "trace", skip(self, message), err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self, message), err)
)]
pub async fn complete_op_waiter(&self, op_id: OperationId, message: T) -> Result<(), RPCError> {
let waiting_op = {
let mut inner = self.inner.lock();
veilid-core/src/rpc_processor/rpc_app_call.rs
+7 -2
View File
@@ -3,7 +3,10 @@ use super::*;
impl RPCProcessor {
// Sends a high level app request and wait for response
// Can be sent via all methods including relays and routes
#[instrument(level = "trace", skip(self, message), fields(message.len = message.len(), ret.latency, ret.len), err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self, message), fields(message.len = message.len(), ret.latency, ret.len), err)
)]
pub async fn rpc_call_app_call(
self,
dest: Destination,
@@ -38,12 +41,14 @@ impl RPCProcessor {
let a_message = app_call_a.destructure();
#[cfg(feature = "verbose-tracing")]
tracing::Span::current().record("ret.latency", latency.as_u64());
#[cfg(feature = "verbose-tracing")]
tracing::Span::current().record("ret.len", a_message.len());
Ok(NetworkResult::value(Answer::new(latency, a_message)))
}
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err))]
pub(crate) async fn process_app_call_q(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_app_message.rs
+5 -2
View File
@@ -3,7 +3,10 @@ use super::*;
impl RPCProcessor {
// Sends a high level app message
// Can be sent via all methods including relays and routes
#[instrument(level = "trace", skip(self, message), fields(message.len = message.len()), err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self, message), fields(message.len = message.len()), err)
)]
pub async fn rpc_call_app_message(
self,
dest: Destination,
@@ -16,7 +19,7 @@ impl RPCProcessor {
self.statement(dest, statement).await
}
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err))]
pub(crate) async fn process_app_message(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_cancel_tunnel.rs
+1 -1
View File
@@ -1,7 +1,7 @@
use super::*;
impl RPCProcessor {
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err))]
pub(crate) async fn process_cancel_tunnel_q(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_complete_tunnel.rs
+1 -1
View File
@@ -1,7 +1,7 @@
use super::*;
impl RPCProcessor {
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err))]
pub(crate) async fn process_complete_tunnel_q(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_find_block.rs
+1 -1
View File
@@ -1,7 +1,7 @@
use super::*;
impl RPCProcessor {
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err))]
pub(crate) async fn process_find_block_q(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_find_node.rs
+5 -2
View File
@@ -7,7 +7,10 @@ impl RPCProcessor {
/// Because this leaks information about the identity of the node itself,
/// replying to this request received over a private route will leak
/// the identity of the node and defeat the private route.
#[instrument(level = "trace", skip(self), err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self), err)
)]
pub async fn rpc_call_find_node(
self,
dest: Destination,
@@ -67,7 +70,7 @@ impl RPCProcessor {
Ok(NetworkResult::value(Answer::new(latency, peers)))
}
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err))]
pub(crate) async fn process_find_node_q(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_get_value.rs
+15 -8
View File
@@ -15,13 +15,17 @@ impl RPCProcessor {
/// Because this leaks information about the identity of the node itself,
/// replying to this request received over a private route will leak
/// the identity of the node and defeat the private route.
#[instrument(level = "trace", skip(self, last_descriptor),
fields(ret.value.data.len,
ret.value.data.seq,
ret.value.data.writer,
ret.peers.len,
ret.latency
),err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self, last_descriptor),
fields(ret.value.data.len,
ret.value.data.seq,
ret.value.data.writer,
ret.peers.len,
ret.latency
),err)
)]
pub async fn rpc_call_get_value(
self,
dest: Destination,
@@ -107,12 +111,15 @@ impl RPCProcessor {
return Ok(NetworkResult::invalid_message("non-closer peers returned"));
}
#[cfg(feature = "verbose-tracing")]
tracing::Span::current().record("ret.latency", latency.as_u64());
#[cfg(feature = "verbose-tracing")]
if let Some(value) = &value {
tracing::Span::current().record("ret.value.data.len", value.value_data().data().len());
tracing::Span::current().record("ret.value.data.seq", value.value_data().seq());
tracing::Span::current().record("ret.value.data.writer", value.value_data().writer().to_string());
}
#[cfg(feature = "verbose-tracing")]
tracing::Span::current().record("ret.peers.len", peers.len());
Ok(NetworkResult::value(Answer::new(
@@ -125,7 +132,7 @@ impl RPCProcessor {
)))
}
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err))]
pub(crate) async fn process_get_value_q(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_return_receipt.rs
+5 -2
View File
@@ -3,7 +3,10 @@ use super::*;
impl RPCProcessor {
// Sends a unidirectional in-band return receipt
// Can be sent via all methods including relays and routes
#[instrument(level = "trace", skip(self, receipt), ret, err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self, receipt), ret, err)
)]
pub async fn rpc_call_return_receipt<D: AsRef<[u8]>>(
self,
dest: Destination,
@@ -20,7 +23,7 @@ impl RPCProcessor {
Ok(NetworkResult::value(()))
}
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err))]
pub(crate) async fn process_return_receipt(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_route.rs
+7 -7
View File
@@ -1,7 +1,7 @@
use super::*;
impl RPCProcessor {
#[instrument(level = "trace", skip_all, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip_all, err))]
async fn process_route_safety_route_hop(
&self,
routed_operation: RoutedOperation,
@@ -52,7 +52,7 @@ impl RPCProcessor {
.await
}
#[instrument(level = "trace", skip_all, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip_all, err))]
async fn process_route_private_route_hop(
&self,
routed_operation: RoutedOperation,
@@ -99,7 +99,7 @@ impl RPCProcessor {
/// Note: it is important that we never respond with a safety route to questions that come
/// in without a private route. Giving away a safety route when the node id is known is
/// a privacy violation!
#[instrument(level = "trace", skip_all, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip_all, err))]
fn process_safety_routed_operation(
&self,
detail: RPCMessageHeaderDetailDirect,
@@ -141,7 +141,7 @@ impl RPCProcessor {
}
/// Process a routed operation that came in over both a safety route and a private route
#[instrument(level = "trace", skip_all, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip_all, err))]
fn process_private_routed_operation(
&self,
detail: RPCMessageHeaderDetailDirect,
@@ -209,7 +209,7 @@ impl RPCProcessor {
Ok(NetworkResult::value(()))
}
#[instrument(level = "trace", skip_all, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip_all, err))]
fn process_routed_operation(
&self,
detail: RPCMessageHeaderDetailDirect,
@@ -239,7 +239,7 @@ impl RPCProcessor {
)
}
}
#[instrument(level = "trace", skip_all, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip_all, err))]
pub(crate) async fn process_private_route_first_hop(
&self,
mut routed_operation: RoutedOperation,
@@ -360,7 +360,7 @@ impl RPCProcessor {
Ok(NetworkResult::value(route_hop))
}
#[instrument(level = "trace", skip(self, msg), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), ret, err))]
pub(crate) async fn process_route(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_set_value.rs
+10 -3
View File
@@ -14,7 +14,9 @@ impl RPCProcessor {
/// Because this leaks information about the identity of the node itself,
/// replying to this request received over a private route will leak
/// the identity of the node and defeat the private route.
#[instrument(level = "trace", skip(self, value, descriptor),
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self, value, descriptor),
fields(value.data.len = value.value_data().data().len(),
value.data.seq = value.value_data().seq(),
value.data.writer = value.value_data().writer().to_string(),
@@ -24,7 +26,8 @@ impl RPCProcessor {
ret.value.data.writer,
ret.peers.len,
ret.latency
), err)]
), err)
)]
pub async fn rpc_call_set_value(
self,
dest: Destination,
@@ -118,13 +121,17 @@ impl RPCProcessor {
return Ok(NetworkResult::invalid_message("non-closer peers returned"));
}
#[cfg(feature = "verbose-tracing")]
tracing::Span::current().record("ret.latency", latency.as_u64());
#[cfg(feature = "verbose-tracing")]
tracing::Span::current().record("ret.set", set);
#[cfg(feature = "verbose-tracing")]
if let Some(value) = &value {
tracing::Span::current().record("ret.value.data.len", value.value_data().data().len());
tracing::Span::current().record("ret.value.data.seq", value.value_data().seq());
tracing::Span::current().record("ret.value.data.writer", value.value_data().writer().to_string());
}
#[cfg(feature = "verbose-tracing")]
tracing::Span::current().record("ret.peers.len", peers.len());
Ok(NetworkResult::value(Answer::new(
@@ -133,7 +140,7 @@ impl RPCProcessor {
)))
}
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err))]
pub(crate) async fn process_set_value_q(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_signal.rs
+5 -2
View File
@@ -3,7 +3,10 @@ use super::*;
impl RPCProcessor {
// Sends a unidirectional signal to a node
// Can be sent via relays but not routes. For routed 'signal' like capabilities, use AppMessage.
#[instrument(level = "trace", skip(self), ret, err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self), ret, err)
)]
pub async fn rpc_call_signal(
self,
dest: Destination,
@@ -29,7 +32,7 @@ impl RPCProcessor {
self.statement(dest, statement).await
}
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err))]
pub(crate) async fn process_signal(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_start_tunnel.rs
+1 -1
View File
@@ -1,7 +1,7 @@
use super::*;
impl RPCProcessor {
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err))]
pub(crate) async fn process_start_tunnel_q(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_status.rs
+5 -2
View File
@@ -15,7 +15,10 @@ impl RPCProcessor {
// direct -> node status + sender info
// safety -> node status
// private -> nothing
#[instrument(level = "trace", skip(self), ret, err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self), ret, err)
)]
pub async fn rpc_call_status(
self,
dest: Destination,
@@ -210,7 +213,7 @@ impl RPCProcessor {
Ok(NetworkResult::value(Answer::new(latency, opt_sender_info)))
}
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err))]
pub(crate) async fn process_status_q(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_supply_block.rs
+1 -1
View File
@@ -1,7 +1,7 @@
use super::*;
impl RPCProcessor {
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err))]
pub(crate) async fn process_supply_block_q(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_validate_dial_info.rs
+5 -2
View File
@@ -2,7 +2,10 @@ use super::*;
impl RPCProcessor {
// Can only be sent directly, not via relays or routes
#[instrument(level = "trace", skip(self), ret, err)]
#[cfg_attr(
feature = "verbose-tracing",
instrument(level = "trace", skip(self), ret, err)
)]
pub async fn rpc_call_validate_dial_info(
self,
peer: NodeRef,
@@ -50,7 +53,7 @@ impl RPCProcessor {
}
}
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err))]
pub(crate) async fn process_validate_dial_info(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_value_changed.rs
+1 -1
View File
@@ -1,7 +1,7 @@
use super::*;
impl RPCProcessor {
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), err))]
pub(crate) async fn process_value_changed(
&self,
msg: RPCMessage,
veilid-core/src/rpc_processor/rpc_watch_value.rs
+1 -1
View File
@@ -1,7 +1,7 @@
use super::*;
impl RPCProcessor {
#[instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err)]
#[cfg_attr(feature="verbose-tracing", instrument(level = "trace", skip(self, msg), fields(msg.operation.op_id), ret, err))]
pub(crate) async fn process_watch_value_q(
&self,
msg: RPCMessage,