WIP: Add optional tracing

Cargo.toml

@@ -8,14 +8,20 @@ keywords = ["agriculture", "can", "canbus", "isobus", "j1939", "agritech", "smar
 
 [dependencies]
 socketcan = { version = "2.0.0", optional = true }
+tracing = { version = "0.1.37", optional = true }
 
 [features]
 default = ["socketcan"]
+# Socketcan driver
 socketcan = ["dep:socketcan"]
+# Optional logging instrumentation
+tracing = ["dep:tracing"]
 
 [dev-dependencies]
 clap = { version = "4.3.19", features = ["derive"] }
 ctrlc = "3.4.0"
-# TODO: Add optional tracing to the main library
-tracing = "0.1.37"
 tracing-subscriber = "0.3.17"
+
+[[example]]
+name = "forward"
+required-features = ["socketcan", "tracing"]

examples/forward.rs

@@ -1,6 +1,7 @@
 use std::sync::mpsc::channel;
 
 use ag_iso_stack::driver::{Driver, DriverReadError, DriverWriteError, Frame, SocketcanDriver};
+use ag_iso_stack::tracing;
 use clap::Parser;
 
 /// Forward CAN traffic from one interface to another
@@ -56,7 +57,7 @@ fn main() {
     let opts = Options::parse();
 
     let subscriber = tracing_subscriber::fmt()
-        // ... add configuration
+        .with_max_level(opts.log_level)
         .finish();
     tracing::subscriber::set_global_default(subscriber)
         .map_err(|_err| eprintln!("Unable to set global default subscriber"))
@@ -84,17 +85,11 @@ fn main() {
 
         let mut frame = Frame::default();
 
-        match read(&mut input, &mut frame, opts.blocking) {
-            Ok(_) => {
-                tracing::info!("Read frame: {frame:?}");
-                tracing::info!("Attempting to write frame");
-                match write(&mut output, &frame, opts.blocking) {
-                    Ok(_) => tracing::info!("Wrote frame: {frame:?}"),
-                    Err(e) => tracing::info!("Failed to write frame: {e:?}"),
-                }
+        #[allow(clippy::collapsible_if)]
+        if read(&mut input, &mut frame, opts.blocking).is_ok() {
+            if write(&mut output, &frame, opts.blocking).is_err() {
+                break;
             }
-            Err(DriverReadError::NoFrameReady) => {}
-            Err(e) => tracing::error!("Failed to read frame: {e:?}"),
         }
     }
 }

src/driver/socketcan.rs

@@ -3,6 +3,7 @@ use socketcan::{CanSocket, Socket};
 use crate::driver::{
     Driver, DriverCloseError, DriverOpenError, DriverReadError, DriverWriteError, Frame,
 };
+use crate::tracing;
 
 impl From<socketcan::Error> for DriverReadError {
     fn from(e: socketcan::Error) -> DriverReadError {
@@ -22,6 +23,7 @@ impl From<socketcan::Error> for DriverWriteError {
     }
 }
 
+#[derive(Debug)]
 enum SocketcanIface {
     Name(String),
     Index(u32),
@@ -53,9 +55,17 @@ impl Driver for SocketcanDriver {
         self.sock.is_some()
     }
     fn open(&mut self) -> Result<(), DriverOpenError> {
-        match &self.iface {
-            SocketcanIface::Name(s) => self.sock = Some(CanSocket::open(s)?),
-            SocketcanIface::Index(i) => self.sock = Some(CanSocket::open_iface(*i)?),
+        tracing::info!("Opening interface {:?}", self.iface);
+        let result = match &self.iface {
+            SocketcanIface::Name(s) => CanSocket::open(s),
+            SocketcanIface::Index(i) => CanSocket::open_iface(*i),
+        };
+        match result {
+            Ok(sock) => self.sock = Some(sock),
+            Err(e) => {
+                tracing::error!("Error '{e:?}' opening interface {:?}", self.iface);
+                return Err(e.into());
+            }
         }
         // NOTE: To get any kind of non-blocking behavior, EVEN if using NonBlockingCan::receive()
         // you MUST set this flag. But setting this flag causes even BlockingCan::receive() to
@@ -65,12 +75,14 @@ impl Driver for SocketcanDriver {
         Ok(())
     }
     fn close(&mut self) -> Result<(), DriverCloseError> {
+        tracing::info!("Closing interface {:?}", self.iface);
         self.sock = None;
         Ok(())
     }
 
     fn read_blocking(&mut self, _frame: &mut Frame) -> Result<(), DriverReadError> {
         let Some(sock) = self.sock.as_mut() else {
+            tracing::warn!("Failed to read from closed interface {:?}", self.iface);
             return Err(DriverReadError::DriverClosed);
         };
 
@@ -79,41 +91,80 @@ impl Driver for SocketcanDriver {
             // as fast as possible.
             match sock.read_frame_timeout(std::time::Duration::from_millis(100)) {
                 Ok(_frame) => {
+                    tracing::trace!("Read frame {_frame:?} from interface {:?}", self.iface);
                     // TODO: convert socketcan CanFrame to Frame
                     return Ok(());
                 }
-                Err(e) => match e.kind() {
-                    std::io::ErrorKind::TimedOut => {}
-                    _ => return Err(e.into()),
-                },
+                Err(e) => {
+                    if e.kind() != std::io::ErrorKind::TimedOut {
+                        tracing::error!(
+                            "Error '{e:?}' receiving frame from interface {:?}",
+                            self.iface
+                        );
+                    } else {
+                        return Err(e.into());
+                    }
+                }
             }
         }
     }
     fn read_nonblocking(&mut self, _frame: &mut Frame) -> Result<(), DriverReadError> {
         let Some(sock) = self.sock.as_mut() else {
+            tracing::warn!("Failed to read from closed interface {:?}", self.iface);
             return Err(DriverReadError::DriverClosed);
         };
-        let _frame = sock.read_frame()?;
+        let _frame = match sock.read_frame() {
+            Ok(frame) => frame,
+            Err(e) => {
+                if e.kind() != std::io::ErrorKind::WouldBlock {
+                    tracing::error!(
+                        "Error '{e:?}' receiving frame from interface {:?}",
+                        self.iface
+                    );
+                }
+                return Err(e.into());
+            }
+        };
+        tracing::trace!("Read frame {_frame:?} from interface {:?}", self.iface);
+
         // TODO: Convert socketcan CanFrame to Frame.
         Ok(())
     }
 
     fn write_blocking(&mut self, _frame: &Frame) -> Result<(), DriverWriteError> {
         let Some(sock) = self.sock.as_mut() else {
+            tracing::warn!("Tried to write to closed interface {:?}", self.iface);
             return Err(DriverWriteError::DriverClosed);
         };
         // TODO: Convert Frame to socketcan CanFrame
         let socketcan_frame = socketcan::CanFrame::default();
-        sock.write_frame_insist(&socketcan_frame)?;
+        match sock.write_frame_insist(&socketcan_frame) {
+            Ok(_) => tracing::trace!("Wrote frame {_frame:?} to interface {:?}", self.iface),
+            Err(_e) => tracing::error!(
+                "Error '{_e:?}' writing frame {_frame:?} to interface {:?}",
+                self.iface
+            ),
+        }
         Ok(())
     }
     fn write_nonblocking(&mut self, _frame: &Frame) -> Result<(), DriverWriteError> {
         let Some(sock) = self.sock.as_mut() else {
+            tracing::warn!("Tried to write to closed interface {:?}", self.iface);
             return Err(DriverWriteError::DriverClosed);
         };
         // TODO: Convert Frame to socketcan CanFrame
         let socketcan_frame = socketcan::CanFrame::default();
-        sock.write_frame(&socketcan_frame)?;
+        match sock.write_frame(&socketcan_frame) {
+            Ok(_) => tracing::trace!("Wrote frame {_frame:?} to interface {:?}", self.iface),
+            Err(_e) => {
+                if _e.kind() != std::io::ErrorKind::WouldBlock {
+                    tracing::error!(
+                        "Error '{_e:?}' writing frame {_frame:?} to interface {:?}",
+                        self.iface
+                    );
+                }
+            }
+        }
         Ok(())
     }
 }

src/lib.rs

@@ -3,3 +3,4 @@
 #![allow(clippy::bool_assert_comparison)]
 
 pub mod driver;
+pub mod tracing;