linux: improve logging

src/platform/linux_usbfs/device.rs

@@ -10,7 +10,7 @@ use std::{
     },
 };
 
-use log::{debug, error};
+use log::{debug, error, warn};
 use rustix::event::epoll;
 use rustix::fd::AsFd;
 use rustix::{
@@ -51,8 +51,8 @@ impl LinuxDevice {
         let active_config = d.path.read_attr("bConfigurationValue")?;
 
         let path = PathBuf::from(format!("/dev/bus/usb/{busnum:03}/{devnum:03}"));
-        debug!("Opening usbfs device {}", path.display());
-        let fd = rustix::fs::open(path, OFlags::RDWR | OFlags::CLOEXEC, Mode::empty())?;
+        let fd = rustix::fs::open(&path, OFlags::RDWR | OFlags::CLOEXEC, Mode::empty())
+            .inspect_err(|e| warn!("Failed to open device {path:?}: {e}"))?;
 
         let descriptors = {
             let mut file = unsafe { ManuallyDrop::new(File::from_raw_fd(fd.as_raw_fd())) };
@@ -229,7 +229,12 @@ impl LinuxDevice {
         self: &Arc<Self>,
         interface_number: u8,
     ) -> Result<Arc<LinuxInterface>, Error> {
-        usbfs::claim_interface(&self.fd, interface_number)?;
+        usbfs::claim_interface(&self.fd, interface_number).inspect_err(|e| {
+            warn!(
+                "Failed to claim interface {interface_number} on device id {dev}: {e}",
+                dev = self.events_id
+            )
+        })?;
         debug!(
             "Claimed interface {interface_number} on device id {dev}",
             dev = self.events_id

src/platform/linux_usbfs/enumeration.rs

@@ -15,26 +15,59 @@ use crate::Speed;
 #[derive(Debug, Clone)]
 pub struct SysfsPath(pub(crate) PathBuf);
 
+#[derive(Debug)]
+pub struct SysfsError(PathBuf, SysfsErrorKind);
+
+#[derive(Debug)]
+enum SysfsErrorKind {
+    Io(io::Error),
+    Parse(String),
+}
+
+impl std::fmt::Display for SysfsError {
+    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
+        write!(f, "failed to read sysfs attribute {}: ", self.0.display())?;
+        match &self.1 {
+            SysfsErrorKind::Io(e) => write!(f, "{e}"),
+            SysfsErrorKind::Parse(v) => write!(f, "couldn't parse value {:?}", v.trim()),
+        }
+    }
+}
+
+impl std::error::Error for SysfsError {
+    fn source(&self) -> Option<&(dyn std::error::Error + 'static)> {
+        match self.1 {
+            SysfsErrorKind::Io(ref e) => Some(e),
+            _ => None,
+        }
+    }
+}
+
+impl From<SysfsError> for io::Error {
+    fn from(value: SysfsError) -> Self {
+        io::Error::other(Box::new(value))
+    }
+}
+
 impl SysfsPath {
-    pub(crate) fn read_attr<T: FromStr>(&self, attr: &str) -> Result<T, io::Error>
-    where
-        T: FromStr,
-        T::Err: std::error::Error + Send + Sync + 'static,
-    {
+    fn parse_attr<T, E>(
+        &self,
+        attr: &str,
+        parse: impl FnOnce(&str) -> Result<T, E>,
+    ) -> Result<T, SysfsError> {
         let attr_path = self.0.join(attr);
-        let read_res = fs::read_to_string(&attr_path);
-        debug!("sysfs read {attr_path:?}: {read_res:?}");
+        fs::read_to_string(&attr_path)
+            .map_err(SysfsErrorKind::Io)
+            .and_then(|v| parse(v.trim()).map_err(|_| SysfsErrorKind::Parse(v)))
+            .map_err(|e| SysfsError(attr_path, e))
+    }
 
-        read_res?
-            .trim()
-            .parse()
-            .map_err(|e| io::Error::new(io::ErrorKind::InvalidData, e))
+    pub(crate) fn read_attr<T: FromStr>(&self, attr: &str) -> Result<T, SysfsError> {
+        self.parse_attr(attr, |s| s.parse())
     }
 
-    fn read_attr_hex<T: FromHexStr>(&self, attr: &str) -> Result<T, io::Error> {
-        let s = self.read_attr::<String>(attr)?;
-        T::from_hex_str(&s)
-            .map_err(|_| io::Error::new(io::ErrorKind::InvalidData, "invalid hex str"))
+    fn read_attr_hex<T: FromHexStr>(&self, attr: &str) -> Result<T, SysfsError> {
+        self.parse_attr(attr, |s| T::from_hex_str(s))
     }
 
     fn children(&self) -> impl Iterator<Item = SysfsPath> {
@@ -89,8 +122,8 @@ pub fn list_devices() -> Result<impl Iterator<Item = DeviceInfo>, Error> {
     }))
 }
 
-pub fn probe_device(path: SysfsPath) -> Result<DeviceInfo, Error> {
-    debug!("probe device {path:?}");
+pub fn probe_device(path: SysfsPath) -> Result<DeviceInfo, SysfsError> {
+    debug!("Probing device {:?}", path.0);
     Ok(DeviceInfo {
         bus_number: path.read_attr("busnum")?,
         device_address: path.read_attr("devnum")?,

src/platform/linux_usbfs/events.rs

@@ -76,7 +76,7 @@ fn event_loop() {
         retry_on_intr(|| epoll::wait(epoll_fd, &mut event_list, -1)).unwrap();
         for event in &event_list {
             let key = event.data.u64() as usize;
-            log::info!("event on {key}");
+            log::trace!("event on {key}");
             let lock = WATCHES.lock().unwrap();
             let Some(watch) = lock.get(key) else { continue };
 

src/platform/linux_usbfs/hotplug.rs

@@ -1,5 +1,5 @@
 use libc::{sockaddr, sockaddr_nl, socklen_t, AF_NETLINK, MSG_DONTWAIT};
-use log::{debug, error, warn};
+use log::{error, trace, warn};
 use rustix::{
     fd::{AsFd, AsRawFd, OwnedFd},
     net::{netlink, socket_with, AddressFamily, SocketFlags, SocketType},
@@ -127,7 +127,7 @@ fn parse_packet(buf: &[u8]) -> Option<HotplugEvent> {
     let mut devpath = None;
 
     for (k, v) in parse_properties(properties_buf) {
-        debug!("uevent property {k} = {v}");
+        trace!("uevent property {k} = {v}");
         match k {
             "SUBSYSTEM" if v != "usb" => return None,
             "DEVTYPE" if v != "usb_device" => return None,
@@ -161,7 +161,7 @@ fn parse_packet(buf: &[u8]) -> Option<HotplugEvent> {
         match probe_device(SysfsPath(path.clone())) {
             Ok(d) => Some(HotplugEvent::Connected(d)),
             Err(e) => {
-                error!("Failed to probe device {path:?}: {e}");
+                warn!("Failed to probe device {path:?}: {e}");
                 None
             }
         }