chore(connlib): allow filtering of wire log target (#5578)

Currently, enabling the `wire` log is an all or nothing approach,
logging incoming and outgoing messages from the TUN device, network and
the portal.

Often, only one or more of these is desired but enabling all of `wire`
spams the logs to the point where one cannot see the information they'd
like. With this PR, we move some of the fields of the `wire` log
statements to the log target instead. This allows controlling the logs
via the `RUST_LOG` env variable.

For example, to only see messages sent and received to the API, one can
set `RUST_LOG=wire::api=trace` which will output something like:

```
2024-06-27T02:12:41.821374Z TRACE wire::api::send: {"topic":"client","event":"phx_join","payload":null,"ref":0}
2024-06-27T02:12:42.030573Z TRACE wire::api::recv: {"event":"phx_reply","ref":0,"topic":"client","payload":{"status":"ok","response":{}}}
```

Similarly, enabling `wire::net=trace` will give you logs for packets
sent over the network:

```
2024-06-27T02:12:50.487503Z TRACE wire::net::send: src=None dst=34.80.2.250:3478 num_bytes=20
2024-06-27T02:12:50.487589Z TRACE wire::net::send: src=None dst=[2600:1900:4030:b0d9:0:5::]:3478 num_bytes=20
2024-06-27T02:12:50.487622Z TRACE wire::net::send: src=None dst=34.87.210.10:3478 num_bytes=20
2024-06-27T02:12:50.487652Z TRACE wire::net::send: src=None dst=[2600:1900:40b0:1504:0:17::]:3478 num_bytes=20
2024-06-27T02:12:50.510049Z TRACE wire::net::recv: src=34.87.210.10:3478 dst=192.168.188.71:39207 num_bytes=32
2024-06-27T02:12:50.510382Z TRACE wire::net::send: src=None dst=34.87.210.10:3478 num_bytes=112
2024-06-27T02:12:50.526947Z TRACE wire::net::recv: src=34.87.210.10:3478 dst=192.168.188.71:39207 num_bytes=92
2024-06-27T02:12:50.527295Z TRACE wire::net::send: src=None dst=34.87.210.10:3478 num_bytes=152
```

These targets have been designed to take up equal amounts of space. All
three types (`dev`, `net`, `api`) have 3 letters and `send` and `recv`
have 4. That way, these logs are always aligned which makes them easier
to scan.
This commit is contained in:
Thomas Eizinger
2024-06-27 16:36:49 +10:00
committed by GitHub
parent e0e9e078a0
commit 9ddee774b4
3 changed files with 7 additions and 7 deletions

View File

@@ -135,7 +135,7 @@ impl Device {
)
})?;
tracing::trace!(target: "wire", from = "device", dst = %packet.destination(), src = %packet.source(), bytes = %packet.packet().len());
tracing::trace!(target: "wire::dev::recv", dst = %packet.destination(), src = %packet.source(), bytes = %packet.packet().len());
Poll::Ready(Ok(packet))
}
@@ -169,7 +169,7 @@ impl Device {
)
})?;
tracing::trace!(target: "wire", from = "device", dst = %packet.destination(), src = %packet.source(), bytes = %packet.packet().len());
tracing::trace!(target: "wire::dev::recv", dst = %packet.destination(), src = %packet.source(), bytes = %packet.packet().len());
Poll::Ready(Ok(packet))
}
@@ -191,7 +191,7 @@ impl Device {
}
pub fn write(&self, packet: IpPacket<'_>) -> io::Result<usize> {
tracing::trace!(target: "wire", to = "device", dst = %packet.destination(), src = %packet.source(), bytes = %packet.packet().len());
tracing::trace!(target: "wire::dev::send", dst = %packet.destination(), src = %packet.source(), bytes = %packet.packet().len());
match packet {
IpPacket::Ipv4(msg) => self.tun()?.write4(msg.packet()),

View File

@@ -283,7 +283,7 @@ impl Socket {
packet,
})
.inspect(|r| {
tracing::trace!(target: "wire", from = "network", src = %r.from, dst = %r.local, num_bytes = %r.packet.len());
tracing::trace!(target: "wire::net::recv", src = %r.from, dst = %r.local, num_bytes = %r.packet.len());
});
return Poll::Ready(Ok(iter));
@@ -322,7 +322,7 @@ impl Socket {
}
fn send(&mut self, transmit: quinn_udp::Transmit) {
tracing::trace!(target: "wire", to = "network", src = ?transmit.src_ip, dst = %transmit.destination, num_bytes = %transmit.contents.len());
tracing::trace!(target: "wire::net::send", src = ?transmit.src_ip, dst = %transmit.destination, num_bytes = %transmit.contents.len());
self.buffered_transmits.push(transmit);

View File

@@ -321,7 +321,7 @@ where
if let Some(message) = self.pending_messages.pop_front() {
match stream.start_send_unpin(Message::Text(message.clone())) {
Ok(()) => {
tracing::trace!(target: "wire", to="portal", %message);
tracing::trace!(target: "wire::api::send", %message);
match stream.poll_flush_unpin(cx) {
Poll::Ready(Ok(())) => {
@@ -359,7 +359,7 @@ where
continue;
};
tracing::trace!(target: "wire", from="portal", %message);
tracing::trace!(target: "wire::api::recv", %message);
let message = match serde_json::from_str::<
PhoenixMessage<TInboundMsg, TOutboundRes>,