Skip to content

Commit f8f7f95

Browse files
authored
fix: better tracing spans (#3399)
## Description This adds tracing spans to tasks we spawn where we didn't do this so far. I also added alpn and remote fields to the router tasks for connections, to match what we do for outgoing connections. Additionally, this improves the display of remote node ids and ALPNs by using tracing's display formatter, to omit the quotes. ## Breaking Changes <!-- Optional, if there are any breaking changes document them, including how to migrate older code. --> ## Notes & open questions <!-- Any notes, remarks or open questions you have to make about the PR. --> ## Change checklist <!-- Remove any that are not relevant. --> - [x] Self-review. - [ ] Documentation updates following the [style guide](https://rust-lang.github.io/rfcs/1574-more-api-documentation-conventions.html#appendix-a-full-conventions-text), if relevant. - [ ] Tests if relevant. - [ ] All breaking changes documented. - [ ] List all breaking changes in the above "Breaking Changes" section. - [ ] Open an issue or PR on any number0 repos that are affected by this breaking change. Give guidance on how the updates should be handled or do the actual updates themselves. The major ones are: - [ ] [`quic-rpc`](https://github.com/n0-computer/quic-rpc) - [ ] [`iroh-gossip`](https://github.com/n0-computer/iroh-gossip) - [ ] [`iroh-blobs`](https://github.com/n0-computer/iroh-blobs) - [ ] [`dumbpipe`](https://github.com/n0-computer/dumbpipe) - [ ] [`sendme`](https://github.com/n0-computer/sendme)
1 parent dd1d692 commit f8f7f95

File tree

3 files changed

+33
-21
lines changed

3 files changed

+33
-21
lines changed

iroh/src/endpoint.rs

Lines changed: 5 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -712,7 +712,7 @@ impl Endpoint {
712712
/// establishing and maintaining direct connections. Carefully test settings you use and
713713
/// consider this currently as still rather experimental.
714714
#[instrument(name = "connect", skip_all, fields(
715-
me = self.node_id().fmt_short(),
715+
me = %self.node_id().fmt_short(),
716716
remote = tracing::field::Empty,
717717
alpn = String::from_utf8_lossy(alpn).to_string(),
718718
))]
@@ -723,7 +723,10 @@ impl Endpoint {
723723
options: ConnectOptions,
724724
) -> Result<Connecting, ConnectWithOptsError> {
725725
let node_addr: NodeAddr = node_addr.into();
726-
tracing::Span::current().record("remote", node_addr.node_id.fmt_short());
726+
tracing::Span::current().record(
727+
"remote",
728+
tracing::field::display(node_addr.node_id.fmt_short()),
729+
);
727730

728731
// Connecting to ourselves is not supported.
729732
ensure!(node_addr.node_id != self.node_id(), SelfConnectSnafu);

iroh/src/magicsock.rs

Lines changed: 19 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -1177,24 +1177,27 @@ impl DirectAddrUpdateState {
11771177
let msock = self.msock.clone();
11781178

11791179
let run_done = self.run_done.clone();
1180-
task::spawn(async move {
1181-
let fut = time::timeout(
1182-
NET_REPORT_TIMEOUT,
1183-
net_reporter.get_report(if_state, why.is_major()),
1184-
);
1185-
match fut.await {
1186-
Ok(report) => {
1187-
msock.net_report.set((Some(report), why)).ok();
1188-
}
1189-
Err(time::Elapsed { .. }) => {
1190-
warn!("net_report report timed out");
1180+
task::spawn(
1181+
async move {
1182+
let fut = time::timeout(
1183+
NET_REPORT_TIMEOUT,
1184+
net_reporter.get_report(if_state, why.is_major()),
1185+
);
1186+
match fut.await {
1187+
Ok(report) => {
1188+
msock.net_report.set((Some(report), why)).ok();
1189+
}
1190+
Err(time::Elapsed { .. }) => {
1191+
warn!("net_report report timed out");
1192+
}
11911193
}
1192-
}
11931194

1194-
// mark run as finished
1195-
debug!("direct addr update done ({:?})", why);
1196-
run_done.send(()).await.ok();
1197-
});
1195+
// mark run as finished
1196+
debug!("direct addr update done ({:?})", why);
1197+
run_done.send(()).await.ok();
1198+
}
1199+
.instrument(tracing::Span::current()),
1200+
);
11981201
}
11991202
}
12001203

iroh/src/protocol.rs

Lines changed: 9 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -46,7 +46,7 @@ use n0_future::{
4646
};
4747
use snafu::{Backtrace, Snafu};
4848
use tokio_util::sync::CancellationToken;
49-
use tracing::{error, info_span, trace, warn, Instrument};
49+
use tracing::{error, field::Empty, info_span, trace, warn, Instrument};
5050

5151
use crate::{
5252
endpoint::{Connecting, Connection, RemoteNodeIdError},
@@ -447,9 +447,10 @@ impl RouterBuilder {
447447

448448
let protocols = protocols.clone();
449449
let token = handler_cancel_token.child_token();
450+
let span = info_span!("router.accept", me=%endpoint.node_id().fmt_short(), remote=Empty, alpn=Empty);
450451
join_set.spawn(async move {
451452
token.run_until_cancelled(handle_connection(incoming, protocols)).await
452-
}.instrument(info_span!("router.accept")));
453+
}.instrument(span));
453454
},
454455
}
455456
}
@@ -471,7 +472,7 @@ impl RouterBuilder {
471472
}
472473
}
473474
};
474-
let task = task::spawn(run_loop_fut);
475+
let task = task::spawn(run_loop_fut.instrument(tracing::Span::current()));
475476
let task = AbortOnDropHandle::new(task);
476477

477478
Router {
@@ -497,12 +498,17 @@ async fn handle_connection(incoming: crate::endpoint::Incoming, protocols: Arc<P
497498
return;
498499
}
499500
};
501+
tracing::Span::current().record("alpn", String::from_utf8_lossy(&alpn).to_string());
500502
let Some(handler) = protocols.get(&alpn) else {
501503
warn!("Ignoring connection: unsupported ALPN protocol");
502504
return;
503505
};
504506
match handler.on_connecting(connecting).await {
505507
Ok(connection) => {
508+
if let Ok(remote) = connection.remote_node_id() {
509+
tracing::Span::current()
510+
.record("remote", tracing::field::display(remote.fmt_short()));
511+
};
506512
if let Err(err) = handler.accept(connection).await {
507513
warn!("Handling incoming connection ended with error: {err}");
508514
}

0 commit comments

Comments
 (0)