From 43d0ea45b950a69aa3a3340b60275f53aa18b254 Mon Sep 17 00:00:00 2001 From: Floris Bruynooghe Date: Fri, 29 Nov 2024 10:48:24 +0100 Subject: [PATCH] ref(iroh): Rename target for events (#2977) ## Description Turns out people will configure logs with `RUST_LOG=iroh=debug` and then the `events` target is completely lost. That's bad! This changes the events to be in the main crate target, so users don't have to separately enable them. It also changes the separators to use the `::`. The driver for this is compatible with the `EnvFliter` syntax, allowing you do do e.g. `RUST_LOG=iroh::events=debug` to enable just events. The main downside is that it is harder to enable events across different crates. But then we only use this in one crate so far, so perhaps that's not an issue yet. Another downside is that `iroh::events` could quite easily become a module name, in which case the targets would conflict. ## Breaking Changes - Events are emitted on different tracing targets: `iroh::events` instead of `events.net`. - Event names have changed to use `::` as separator, previously this was `.`. ## Notes & open questions Perhaps there is a better name than `events` that is less likely to conflict with a real module? Maybe we could use an illegal character? Experimenting with `iroh::-events::` as prefix does seem to work: it is accepted by the tracing and the EnvFilter is fine with it. ## Change checklist - [x] Self-review. - [x] 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. - [x] Tests if relevant. - [x] All breaking changes documented. --- iroh-relay/src/client.rs | 2 +- iroh/README.md | 21 ++++++++++++++------- iroh/src/magicsock.rs | 8 ++++---- iroh/src/magicsock/node_map/node_state.rs | 8 ++++---- iroh/src/magicsock/node_map/path_state.rs | 4 ++-- 5 files changed, 25 insertions(+), 18 deletions(-) diff --git a/iroh-relay/src/client.rs b/iroh-relay/src/client.rs index 148c08463c..680771f2b1 100644 --- a/iroh-relay/src/client.rs +++ b/iroh-relay/src/client.rs @@ -620,7 +620,7 @@ impl Actor { } event!( - target: "events.net.relay.connected", + target: "iroh::_events::relay::connected", Level::DEBUG, home = self.is_preferred, url = %self.url, diff --git a/iroh/README.md b/iroh/README.md index 1f851222e7..3727aa750c 100644 --- a/iroh/README.md +++ b/iroh/README.md @@ -20,9 +20,10 @@ The library uses [tracing](https://docs.rs/tracing) to for logging as well as for **structured events**. Events are different from normal logging by convention: -- The [target] has a prefix of `events` and target names are dot-separated. +- The [target] has a prefix of `$crate_name::_events` and target names + are `::` separated. - For this library the target will always start with `events.net.`. + For this library the target will always start with `iroh::_events::`. - There is **no message**. @@ -32,18 +33,24 @@ logging by convention: - The [Level] is always `DEBUG`. +This is a compromise between being able to process events using +automated tooling using custom subscribers and them still producing +distinguishing output in logs when using the default tracing +subscriber formatters. While still being unlikely to conflict with +real modules. + [target]: https://docs.rs/tracing/latest/tracing/struct.Metadata.html#method.target [fields]: https://docs.rs/tracing/latest/tracing/#recording-fields [Level]: https://docs.rs/tracing/latest/tracing/struct.Level.html ### Using events -If desired an application can use the `events.*` target to handle -events by a different subscriber. However with the default file -logging it is already easy to search for all events, e.g. using +If desired an application can use the `$crate_name::_events` target to +handle events by a different subscriber. However with the default +file logging it is already easy to search for all events, e.g. using ripgrep: -`rg 'events\.[a-z_\-.]+' path/to/iroh/logs/iroh.YYYY-MM-DD-NN.log` +`rg 'events::[a-z_\-:]+' path/to/iroh/logs/iroh.YYYY-MM-DD-NN.log` Which will also highlight the full target name by default on a colour supporting terminal. @@ -60,7 +67,7 @@ recommended to write them using the `event!()` macro: ```rust event!( - target: "event.net.subject", + target: "iroh::_event::subject", Level::DEBUG, field = value, ); diff --git a/iroh/src/magicsock.rs b/iroh/src/magicsock.rs index 12dc5ed529..d88408d48d 100644 --- a/iroh/src/magicsock.rs +++ b/iroh/src/magicsock.rs @@ -878,7 +878,7 @@ impl MagicSock { match src { DiscoMessageSource::Relay { url, .. } => { event!( - target: "events.net.call-me-maybe.recv", + target: "iroh::_events::call-me-maybe::recv", Level::DEBUG, remote_node = sender.fmt_short(), via = ?url, @@ -934,7 +934,7 @@ impl MagicSock { ping_observed_addr: addr.clone(), }); event!( - target: "events.net.pong.sent", + target: "iroh::_events::pong::sent", Level::DEBUG, remote_node = %sender.fmt_short(), dst = ?addr, @@ -1060,7 +1060,7 @@ impl MagicSock { Ok(()) => { if let disco::Message::CallMeMaybe(CallMeMaybe { ref my_numbers }) = msg { event!( - target: "events.net.call-me-maybe.sent", + target: "iroh::_events::call-me-maybe::sent", Level::DEBUG, remote_node = %dst.fmt_short(), via = ?url, @@ -2465,7 +2465,7 @@ impl DiscoveredDirectAddrs { let updated = self.addrs.update(addrs).is_ok(); if updated { event!( - target: "events.net.direct_addrs", + target: "iroh::_events::direct_addrs", Level::DEBUG, addrs = ?self.addrs.get(), ); diff --git a/iroh/src/magicsock/node_map/node_state.rs b/iroh/src/magicsock/node_map/node_state.rs index 42cd36941d..d99edc170a 100644 --- a/iroh/src/magicsock/node_map/node_state.rs +++ b/iroh/src/magicsock/node_map/node_state.rs @@ -315,7 +315,7 @@ impl NodeState { if let Ok(prev_typ) = self.conn_type.update(typ.clone()) { // The connection type has changed. event!( - target: "events.net.conn_type.changed", + target: "iroh::_events::conn_type::changed", Level::DEBUG, remote_node = %self.node_id.fmt_short(), conn_type = ?typ, @@ -470,7 +470,7 @@ impl NodeState { trace!(tx = %hex::encode(tx_id), %dst, ?purpose, dst = %self.node_id.fmt_short(), "start ping"); event!( - target: "events.net.ping.sent", + target: "iroh::_events::ping::sent", Level::DEBUG, remote_node = %self.node_id.fmt_short(), ?dst, @@ -761,7 +761,7 @@ impl NodeState { } }; event!( - target: "events.net.ping.recv", + target: "iroh::_events::ping::recv", Level::DEBUG, remote_node = %self.node_id.fmt_short(), src = ?path, @@ -863,7 +863,7 @@ impl NodeState { src: SendAddr, ) -> Option<(SocketAddr, PublicKey)> { event!( - target: "events.net.pong.recv", + target: "iroh::_events::pong::recv", Level::DEBUG, remote_node = self.node_id.fmt_short(), ?src, diff --git a/iroh/src/magicsock/node_map/path_state.rs b/iroh/src/magicsock/node_map/path_state.rs index b8ff645e63..66e9ea991d 100644 --- a/iroh/src/magicsock/node_map/path_state.rs +++ b/iroh/src/magicsock/node_map/path_state.rs @@ -120,7 +120,7 @@ impl PathState { if let SendAddr::Udp(ref path) = self.path { if self.recent_pong.is_none() { event!( - target: "events.net.holepunched", + target: "iroh::_events::holepunched", Level::DEBUG, remote_node = %self.node_id.fmt_short(), path = ?path, @@ -259,7 +259,7 @@ impl PathState { None => { if let SendAddr::Udp(ref addr) = self.path { event!( - target: "events.net.holepunched", + target: "iroh::_events::holepunched", Level::DEBUG, remote_node = %self.node_id.fmt_short(), path = ?addr,