Skip to content

Commit

Permalink
refactor(iroh-net): A bunch of logging improvements (#1982)
Browse files Browse the repository at this point in the history
- Make sure the DerpMap has a nicer Debug impl that shows the map with
URLs instead of structs.

- Do not log individual packets on debug level, downgrade those to
trace.

- Log derp URLs and URLs rather than structs in various places.

- Log sending of DISCO messages on debug, these are generally
interesting and do not transfer bulk data.

## Description

<!-- A summary of what this pull request achieves and a rough list of
changes. -->

## Notes & open questions

<!-- Any notes, remarks or open questions you have to make about the PR.
-->

## Change checklist

- [x] Self-review.
- [x] Documentation updates if relevant.
- [x] Tests if relevant.
  • Loading branch information
flub authored Jan 29, 2024
1 parent 12e42b3 commit 9dd77fa
Show file tree
Hide file tree
Showing 6 changed files with 21 additions and 11 deletions.
4 changes: 2 additions & 2 deletions iroh-net/src/derp/client.rs
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,7 @@ use futures::{Sink, SinkExt, StreamExt};
use tokio::io::{AsyncRead, AsyncWrite};
use tokio::sync::mpsc;
use tokio_util::codec::{FramedRead, FramedWrite};
use tracing::{debug, info_span, Instrument};
use tracing::{debug, info_span, trace, Instrument};

use super::codec::PER_CLIENT_READ_QUEUE_DEPTH;
use super::{
Expand Down Expand Up @@ -83,7 +83,7 @@ impl Client {
///
/// Errors if the packet is larger than [`super::MAX_PACKET_SIZE`]
pub async fn send(&self, dstkey: PublicKey, packet: Bytes) -> Result<()> {
debug!(%dstkey, len = packet.len(), "[DERP] send");
trace!(%dstkey, len = packet.len(), "[DERP] send");

self.inner
.writer_channel
Expand Down
2 changes: 1 addition & 1 deletion iroh-net/src/derp/http/client.rs
Original file line number Diff line number Diff line change
Expand Up @@ -840,7 +840,7 @@ impl Actor {
}

async fn send(&mut self, dst_key: PublicKey, b: Bytes) -> Result<(), ClientError> {
debug!(dst = %dst_key.fmt_short(), len = b.len(), "send");
trace!(dst = %dst_key.fmt_short(), len = b.len(), "send");
let (client, _, _) = self.connect().await?;
if client.send(dst_key, b).await.is_err() {
self.close_for_reconnect().await;
Expand Down
12 changes: 11 additions & 1 deletion iroh-net/src/derp/map.rs
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,7 @@ pub enum DerpMode {
}

/// Configuration of all the Derp servers that can be used.
#[derive(Debug, Clone, PartialEq, Eq)]
#[derive(Clone, PartialEq, Eq)]
pub struct DerpMap {
/// A map of the different derp IDs to the [`DerpNode`] information
nodes: Arc<BTreeMap<Url, Arc<DerpNode>>>,
Expand Down Expand Up @@ -104,6 +104,16 @@ impl DerpMap {
}
}

impl fmt::Debug for DerpMap {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
let mut m = f.debug_map();
for (url, node) in self.nodes.iter() {
m.entry(&url.as_str(), node);
}
m.finish()
}
}

impl fmt::Display for DerpMap {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
fmt::Debug::fmt(&self, f)
Expand Down
8 changes: 4 additions & 4 deletions iroh-net/src/magicsock.rs
Original file line number Diff line number Diff line change
Expand Up @@ -727,14 +727,14 @@ impl Inner {
tx_id,
node_key: self.public_key(),
});
trace!(dst = ?dst, %tx_id, ?purpose, "send ping");
trace!(%dst, %tx_id, ?purpose, "send ping");
let sent = match dst {
SendAddr::Udp(addr) => self.udp_disco_sender.try_send((addr, dst_key, msg)).is_ok(),
SendAddr::Derp(ref url) => self.send_disco_message_derp(url, dst_key, msg),
};
if sent {
let msg_sender = self.actor_sender.clone();
debug!(dst = ?dst, tx = %hex::encode(tx_id), ?purpose, "ping sent (queued)");
debug!(%dst, tx = %hex::encode(tx_id), ?purpose, "ping sent (queued)");
self.node_map
.notify_ping_sent(id, dst, tx_id, purpose, msg_sender);
} else {
Expand All @@ -756,7 +756,7 @@ impl Inner {
});
ready!(self.poll_send_disco_message(dst.clone(), *dst_key, msg, cx))?;
let msg_sender = self.actor_sender.clone();
debug!(dst = ?dst, tx = %hex::encode(tx_id), ?purpose, "ping sent (polled)");
debug!(%dst, tx = %hex::encode(tx_id), ?purpose, "ping sent (polled)");
self.node_map
.notify_ping_sent(*id, dst.clone(), *tx_id, *purpose, msg_sender);
Poll::Ready(Ok(()))
Expand Down Expand Up @@ -801,7 +801,7 @@ impl Inner {
}

fn send_disco_message_derp(&self, url: &Url, dst_key: PublicKey, msg: disco::Message) -> bool {
trace!(node = %dst_key.fmt_short(), %url, %msg, "send disco message (derp)");
debug!(node = %dst_key.fmt_short(), %url, %msg, "send disco message (derp)");
let pkt = self.encode_disco_message(dst_key, &msg);
inc!(MagicsockMetrics, send_disco_derp);
if self.try_send_derp(url, dst_key, smallvec![pkt]) {
Expand Down
2 changes: 1 addition & 1 deletion iroh-net/src/magicsock/derp_actor.rs
Original file line number Diff line number Diff line change
Expand Up @@ -366,7 +366,7 @@ impl DerpActor {
}

async fn send_derp(&mut self, url: &Url, contents: DerpContents, peer: PublicKey) {
debug!(%url, peer = %peer.fmt_short(),len = contents.iter().map(|c| c.len()).sum::<usize>(), "sending derp");
trace!(%url, peer = %peer.fmt_short(),len = contents.iter().map(|c| c.len()).sum::<usize>(), "sending derp");
// Derp Send
let derp_client = self.connect_derp(url, Some(&peer)).await;
for content in &contents {
Expand Down
4 changes: 2 additions & 2 deletions iroh-net/src/magicsock/peer_map/endpoint.rs
Original file line number Diff line number Diff line change
Expand Up @@ -406,7 +406,7 @@ impl Endpoint {
// queue a ping to our derper, if needed.
if let Some((url, state)) = self.derp_url.as_ref() {
if state.needs_ping(&now) {
debug!(?url, "node's derp needs ping");
debug!(%url, "node's derp needs ping");
if let Some(msg) =
self.start_ping(SendAddr::Derp(url.clone()), DiscoPingPurpose::Discovery)
{
Expand Down Expand Up @@ -463,7 +463,7 @@ impl Endpoint {
// message to our node via DERP informing them that we've
// sent so our firewall ports are probably open and now
// would be a good time for them to connect.
debug!(?url, "queue call-me-maybe");
debug!(%url, "queue call-me-maybe");
msgs.push(PingAction::SendCallMeMaybe {
derp_url: url.clone(),
dst_key: self.public_key,
Expand Down

0 comments on commit 9dd77fa

Please sign in to comment.