From 60a79a20ed168770e5cd5f3c47ca28f84d716621 Mon Sep 17 00:00:00 2001 From: Floris Bruynooghe Date: Thu, 28 Nov 2024 16:48:49 +0100 Subject: [PATCH 1/2] ref(iroh): Rename target for events Turns out people will configure logs with `RUST_LOG=iroh=debug` and then the `events` target is completely lost. That's bad! --- iroh-relay/src/client.rs | 2 +- iroh/README.md | 15 ++++++++------- 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, 19 insertions(+), 18 deletions(-) diff --git a/iroh-relay/src/client.rs b/iroh-relay/src/client.rs index 148c08463c..c8c171368f 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..270d1fdb32 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**. @@ -38,12 +39,12 @@ logging by convention: ### 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 +61,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..312816bf1c 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..f96f446379 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..a192443dbb 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, From 7acd54f5a34499966991534b863b7f7261fe2df5 Mon Sep 17 00:00:00 2001 From: Floris Bruynooghe Date: Fri, 29 Nov 2024 10:38:57 +0100 Subject: [PATCH 2/2] Use _event, describe the tradeoffs made in the readme. --- iroh-relay/src/client.rs | 2 +- iroh/README.md | 14 ++++++++++---- 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, 21 insertions(+), 15 deletions(-) diff --git a/iroh-relay/src/client.rs b/iroh-relay/src/client.rs index c8c171368f..680771f2b1 100644 --- a/iroh-relay/src/client.rs +++ b/iroh-relay/src/client.rs @@ -620,7 +620,7 @@ impl Actor { } event!( - target: "iroh::events::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 270d1fdb32..3727aa750c 100644 --- a/iroh/README.md +++ b/iroh/README.md @@ -20,10 +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 `$crate_name::events` and target names +- The [target] has a prefix of `$crate_name::_events` and target names are `::` separated. - For this library the target will always start with `iroh::events::`. + For this library the target will always start with `iroh::_events::`. - There is **no message**. @@ -33,13 +33,19 @@ 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 `$crate_name::events` target to +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: @@ -61,7 +67,7 @@ recommended to write them using the `event!()` macro: ```rust event!( - target: "iroh::event::subject", + target: "iroh::_event::subject", Level::DEBUG, field = value, ); diff --git a/iroh/src/magicsock.rs b/iroh/src/magicsock.rs index 312816bf1c..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: "iroh::events::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: "iroh::events::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: "iroh::events::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: "iroh::events::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 f96f446379..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: "iroh::events::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: "iroh::events::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: "iroh::events::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: "iroh::events::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 a192443dbb..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: "iroh::events::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: "iroh::events::holepunched", + target: "iroh::_events::holepunched", Level::DEBUG, remote_node = %self.node_id.fmt_short(), path = ?addr,