Skip to content

Commit

Permalink
ref(iroh): Rename target for events (#2977)
Browse files Browse the repository at this point in the history
## 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.
  • Loading branch information
flub authored Nov 29, 2024
1 parent fb20176 commit 43d0ea4
Show file tree
Hide file tree
Showing 5 changed files with 25 additions and 18 deletions.
2 changes: 1 addition & 1 deletion iroh-relay/src/client.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down
21 changes: 14 additions & 7 deletions iroh/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -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**.

Expand All @@ -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.
Expand All @@ -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,
);
Expand Down
8 changes: 4 additions & 4 deletions iroh/src/magicsock.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down Expand Up @@ -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,
Expand Down Expand Up @@ -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,
Expand Down Expand Up @@ -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(),
);
Expand Down
8 changes: 4 additions & 4 deletions iroh/src/magicsock/node_map/node_state.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down Expand Up @@ -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,
Expand Down Expand Up @@ -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,
Expand Down Expand Up @@ -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,
Expand Down
4 changes: 2 additions & 2 deletions iroh/src/magicsock/node_map/path_state.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down Expand Up @@ -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,
Expand Down

0 comments on commit 43d0ea4

Please sign in to comment.