Switch logging to use tracing instead of log

Tracing has support for intervals and a great os_log integration.

tun/Cargo.toml

@@ -10,6 +10,7 @@ nix = { version = "0.26", features = ["ioctl"] }
 socket2 = "0.4"
 tokio = { version = "1.28", features = [] }
 byteorder = "1.4"
+tracing = "0.1"
 log = "0.4"
 serde = { version = "1", features = ["derive"], optional = true }
 

tun/src/lib.rs

@@ -1,3 +1,5 @@
+#![deny(missing_debug_implementations)]
+
 #[cfg(target_os = "windows")]
 #[path = "windows/mod.rs"]
 mod imp;

tun/src/tokio/mod.rs

@@ -1,17 +1,21 @@
 use std::io;
 use tokio::io::unix::AsyncFd;
+use tracing::instrument;
 
+#[derive(Debug)]
 pub struct TunInterface {
     inner: AsyncFd<crate::TunInterface>,
 }
 
 impl TunInterface {
+    #[instrument]
     pub fn new(tun: crate::TunInterface) -> io::Result<Self> {
         Ok(Self {
             inner: AsyncFd::new(tun)?,
         })
     }
 
+    #[instrument]
     pub async fn write(&self, buf: &[u8]) -> io::Result<usize> {
         loop {
             let mut guard = self.inner.writable().await?;
@@ -22,6 +26,7 @@ impl TunInterface {
         }
     }
 
+    #[instrument]
     pub async fn read(&mut self, buf: &mut [u8]) -> io::Result<usize> {
         loop {
             let mut guard = self.inner.readable_mut().await?;

tun/src/unix/apple/mod.rs

@@ -1,12 +1,13 @@
 use byteorder::{ByteOrder, NetworkEndian};
 use fehler::throws;
 use libc::{c_char, iovec, writev, AF_INET, AF_INET6};
-use log::info;
+use tracing::info;
 use socket2::{Domain, SockAddr, Socket, Type};
 use std::io::IoSlice;
 use std::net::{Ipv4Addr, SocketAddrV4};
 use std::os::fd::{AsRawFd, RawFd};
 use std::{io::Error, mem};
+use tracing::instrument;
 
 mod kern_control;
 mod sys;
@@ -23,16 +24,19 @@ pub struct TunInterface {
 
 impl TunInterface {
     #[throws]
+    #[instrument]
     pub fn new() -> TunInterface {
         Self::new_with_options(TunOptions::new())?
     }
 
     #[throws]
+    #[instrument]
     pub fn new_with_options(_: TunOptions) -> TunInterface {
         TunInterface::connect(0)?
     }
 
     #[throws]
+    #[instrument]
     fn connect(index: u32) -> TunInterface {
         use socket2::{Domain, Protocol, Socket, Type};
 
@@ -48,6 +52,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn name(&self) -> String {
         let mut buf = [0 as c_char; sys::IFNAMSIZ];
         let mut len = buf.len() as sys::socklen_t;
@@ -62,6 +67,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     fn ifreq(&self) -> sys::ifreq {
         let mut iff: sys::ifreq = unsafe { mem::zeroed() };
         iff.ifr_name = string_to_ifname(&self.name()?);
@@ -69,6 +75,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn set_ipv4_addr(&self, addr: Ipv4Addr) {
         let addr = SockAddr::from(SocketAddrV4::new(addr, 0));
         let mut iff = self.ifreq()?;
@@ -78,6 +85,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn ipv4_addr(&self) -> Ipv4Addr {
         let mut iff = self.ifreq()?;
         self.perform(|fd| unsafe { sys::if_get_addr(fd, &mut iff) })?;
@@ -87,11 +95,15 @@ impl TunInterface {
 
     #[throws]
     fn perform<R>(&self, perform: impl FnOnce(RawFd) -> Result<R, nix::Error>) -> R {
+        let span = tracing::info_span!("perform", fd = self.as_raw_fd());
+        let _enter = span.enter();
+
         let socket = Socket::new(Domain::IPV4, Type::DGRAM, None)?;
         perform(socket.as_raw_fd())?
     }
 
     #[throws]
+    #[instrument]
     pub fn mtu(&self) -> i32 {
         let mut iff = self.ifreq()?;
         self.perform(|fd| unsafe { sys::if_get_mtu(fd, &mut iff) })?;
@@ -101,6 +113,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn set_mtu(&self, mtu: i32) {
         let mut iff = self.ifreq()?;
         iff.ifr_ifru.ifru_mtu = mtu;
@@ -109,6 +122,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn netmask(&self) -> Ipv4Addr {
         let mut iff = self.ifreq()?;
         self.perform(|fd| unsafe { sys::if_get_netmask(fd, &mut iff) })?;
@@ -120,6 +134,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn set_netmask(&self, addr: Ipv4Addr) {
         let addr = SockAddr::from(SocketAddrV4::new(addr, 0));
         let mut iff = self.ifreq()?;
@@ -133,6 +148,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn send(&self, buf: &[u8]) -> usize {
         use std::io::ErrorKind;
         let proto = match buf[0] >> 4 {

tun/src/unix/linux/mod.rs

@@ -8,7 +8,7 @@ use std::net::{Ipv4Addr, Ipv6Addr, SocketAddrV4};
 use std::os::fd::RawFd;
 use std::os::unix::io::{AsRawFd, FromRawFd, IntoRawFd};
 
-use log::info;
+use tracing::{info, instrument};
 
 use libc::in6_ifreq;
 
@@ -23,11 +23,13 @@ pub struct TunInterface {
 
 impl TunInterface {
     #[throws]
+    #[instrument]
     pub fn new() -> TunInterface {
         Self::new_with_options(TunOptions::new())?
     }
 
     #[throws]
+    #[instrument]
     pub(crate) fn new_with_options(options: TunOptions) -> TunInterface {
         let file = OpenOptions::new()
             .read(true)
@@ -59,6 +61,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn name(&self) -> String {
         let mut iff = unsafe { mem::zeroed() };
         unsafe { sys::tun_get_iff(self.socket.as_raw_fd(), &mut iff)? };
@@ -66,6 +69,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     fn ifreq(&self) -> sys::ifreq {
         let mut iff: sys::ifreq = unsafe { mem::zeroed() };
         iff.ifr_name = string_to_ifname(&self.name()?);
@@ -73,6 +77,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     fn in6_ifreq(&self) -> in6_ifreq {
         let mut iff: in6_ifreq = unsafe { mem::zeroed() };
         iff.ifr6_ifindex = self.index()?;
@@ -80,6 +85,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn index(&self) -> i32 {
         let mut iff = self.ifreq()?;
         self.perform(|fd| unsafe { sys::if_get_index(fd, &mut iff) })?;
@@ -87,6 +93,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn set_ipv4_addr(&self, addr: Ipv4Addr) {
         let addr = SockAddr::from(SocketAddrV4::new(addr, 0));
         let mut iff = self.ifreq()?;
@@ -96,6 +103,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn ipv4_addr(&self) -> Ipv4Addr {
         let mut iff = self.ifreq()?;
         self.perform(|fd| unsafe { sys::if_get_addr(fd, &mut iff) })?;
@@ -104,6 +112,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn set_broadcast_addr(&self, addr: Ipv4Addr) {
         let addr = SockAddr::from(SocketAddrV4::new(addr, 0));
         let mut iff = self.ifreq()?;
@@ -117,6 +126,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn broadcast_addr(&self) -> Ipv4Addr {
         let mut iff = self.ifreq()?;
         self.perform(|fd| unsafe { sys::if_get_brdaddr(fd, &mut iff) })?;
@@ -126,6 +136,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn set_ipv6_addr(&self, addr: Ipv6Addr) {
         let mut iff = self.in6_ifreq()?;
         iff.ifr6_addr.s6_addr = addr.octets();
@@ -134,6 +145,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn set_mtu(&self, mtu: i32) {
         let mut iff = self.ifreq()?;
         iff.ifr_ifru.ifru_mtu = mtu;
@@ -142,6 +154,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn mtu(&self) -> i32 {
         let mut iff = self.ifreq()?;
         self.perform(|fd| unsafe { sys::if_get_mtu(fd, &mut iff) })?;
@@ -151,6 +164,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn set_netmask(&self, addr: Ipv4Addr) {
         let addr = SockAddr::from(SocketAddrV4::new(addr, 0));
 
@@ -167,6 +181,7 @@ impl TunInterface {
     }
 
     #[throws]
+    #[instrument]
     pub fn netmask(&self) -> Ipv4Addr {
         let mut iff = self.ifreq()?;
         self.perform(|fd| unsafe { sys::if_get_netmask(fd, &mut iff) })?;
@@ -179,17 +194,24 @@ impl TunInterface {
 
     #[throws]
     fn perform<R>(&self, perform: impl FnOnce(RawFd) -> Result<R, nix::Error>) -> R {
+        let span = tracing::info_span!("perform");
+        let _enter = span.enter();
+
         let socket = Socket::new(Domain::IPV4, Type::DGRAM, None)?;
         perform(socket.as_raw_fd())?
     }
 
     #[throws]
     fn perform6<R>(&self, perform: impl FnOnce(RawFd) -> Result<R, nix::Error>) -> R {
+        let span = tracing::info_span!("perform");
+        let _enter = span.enter();
+
         let socket = Socket::new(Domain::IPV6, Type::DGRAM, None)?;
         perform(socket.as_raw_fd())?
     }
 
     #[throws]
+    #[instrument]
     pub fn send(&self, buf: &[u8]) -> usize {
         self.socket.send(buf)?
     }

tun/src/unix/mod.rs

@@ -2,6 +2,7 @@ use std::{
     io::{Error, Read},
     os::fd::{AsRawFd, FromRawFd, IntoRawFd, RawFd},
 };
+use tracing::instrument;
 
 use super::TunOptions;
 
@@ -41,11 +42,13 @@ impl IntoRawFd for TunInterface {
 
 impl TunInterface {
     #[throws]
+    #[instrument]
     pub fn recv(&mut self, buf: &mut [u8]) -> usize {
         self.socket.read(buf)?
     }
 }
 
+#[instrument]
 pub fn ifname_to_string(buf: [libc::c_char; libc::IFNAMSIZ]) -> String {
     // TODO: Switch to `CStr::from_bytes_until_nul` when stabilized
     unsafe {
@@ -56,6 +59,7 @@ pub fn ifname_to_string(buf: [libc::c_char; libc::IFNAMSIZ]) -> String {
     }
 }
 
+#[instrument]
 pub fn string_to_ifname(name: &str) -> [libc::c_char; libc::IFNAMSIZ] {
     let mut buf = [0 as libc::c_char; libc::IFNAMSIZ];
     let len = name.len().min(buf.len());

tun/src/unix/queue.rs

@@ -5,15 +5,18 @@ use std::{
     mem::MaybeUninit,
     os::unix::io::{AsRawFd, IntoRawFd, RawFd},
 };
+use tracing::instrument;
 
 use crate::TunInterface;
 
+#[derive(Debug)]
 pub struct TunQueue {
     socket: socket2::Socket,
 }
 
 impl TunQueue {
     #[throws]
+    #[instrument]
     pub fn recv(&self, buf: &mut [MaybeUninit<u8>]) -> usize {
         self.socket.recv(buf)?
     }

tun/src/windows/mod.rs

@@ -1,3 +1,4 @@
+use std::fmt::Debug;
 use fehler::throws;
 use std::io::Error;
 use std::ptr;
@@ -14,6 +15,15 @@ pub struct TunInterface {
     name: String,
 }
 
+impl Debug for TunInterface {
+    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
+        f.debug_struct("TunInterface")
+            .field("handle", &"SYS_WINTUN_ADAPTER_HANDLE".to_string())
+            .field("name", &self.name)
+            .finish()
+    }
+}
+
 impl TunInterface {
     #[throws]
     pub fn new() -> TunInterface {

tun/src/windows/queue.rs

@@ -1 +1,2 @@
+#[derive(Debug)]
 pub struct TunQueue;