Merge pull request #2 from vitalyvb/updates03

Fix EP transactions, improve logging, 0.3.0

CHANGELOG.md

@@ -6,6 +6,23 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ## [Unreleased]
 
+## [0.3.0] - 2024-04-22
+
+### Added
+- `initlog` feature
+- `UsbDeviceCtx::initialize` which initializes logging by
+default if `initlog` feature is enabled
+- `Device::poll` which allows calling `poll` from the test case
+
+### Fixed
+- Termination condition in `Device::ep_raw`. Data phase stops
+when `UsbClass` does not consume data from the endpoint buffer
+- Incorrect internal `UsbBusImpl::ep_is_empty` condition check
+
+### Changed
+- Significanlty improved logging
+- `UsbDeviceCtx::post_poll` renamed and changed to `UsbDeviceCtx::hook`
+
 ## [0.2.1] - 2024-04-13
 
 ### Fixed
@@ -27,7 +44,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 First version.
 
-[Unreleased]: https://github.com/vitalyvb/usbd-class-tester/compare/v0.2.1...HEAD
+[Unreleased]: https://github.com/vitalyvb/usbd-class-tester/compare/v0.3.0...HEAD
+[0.3.0]: https://github.com/vitalyvb/usbd-class-tester/compare/v0.2.1...v0.3.0
 [0.2.1]: https://github.com/vitalyvb/usbd-class-tester/compare/v0.2.0...v0.2.1
 [0.2.0]: https://github.com/vitalyvb/usbd-class-tester/compare/v0.1.0...v0.2.0
 [0.1.0]: https://github.com/vitalyvb/usbd-class-tester/releases/tag/v0.1.0

Cargo.toml

@@ -1,6 +1,6 @@
 [package]
 name = "usbd-class-tester"
-version = "0.2.1"
+version = "0.3.0"
 edition = "2021"
 
 description = "Library for testing usb-device device classes."
@@ -13,5 +13,16 @@ exclude = [
     ".github",
 ]
 
+[features]
+default = ["initlog"]
+initlog = ["dep:env_logger"]
+
 [dependencies.usb-device]
 version = "0.3.2"
+
+[dependencies.log]
+version = "0.4"
+
+[dependencies.env_logger]
+version = "0.11"
+optional = true

README.md

@@ -96,3 +96,5 @@ fn test_interface_get_status() {
 }
 ```
 
+USB debug logging can be enabled, for example, by running tests with:
+`$ RUST_LOG=trace cargo test -- --nocapture`

src/bus.rs

@@ -4,6 +4,7 @@
 //!
 //! This implementation is not complete and probably buggy.
 //!
+use log::{debug, info, trace};
 use std::{cell::RefCell, cmp::min, rc::Rc};
 
 use usb_device::bus::PollResult;
@@ -51,6 +52,13 @@ impl EndpointImpl {
             self.setup = setup;
             self.read_ready = true;
         }
+
+        debug!(
+            "EP : set data to read: {} bytes, setup: {}",
+            self.read_len, setup
+        );
+        trace!("EP : {} {:02x?}", if setup { "<==" } else { "<--" }, data);
+
         self.read_len
     }
 
@@ -62,16 +70,23 @@ impl EndpointImpl {
             self.read_ready = true;
             self.read_len += len;
         }
+
+        debug!("EP : append data to read: {}", len);
+        trace!("EP : <-+ {:02x?}", &data[..len]);
+
         len
     }
 
     /// Returns data that was written by usb-device to the Endpoint
     fn get_write(&mut self, data: &mut [u8]) -> usize {
         let res = self.write_len;
-        dbg!("g", self.write_len);
         self.write_len = 0;
         data[..res].clone_from_slice(&self.write[..res]);
         self.write_done = true;
+
+        debug!("EP : retrieve written data: {}", res);
+        trace!("EP : --> {:02x?}", &data[..res]);
+
         res
     }
 }
@@ -146,8 +161,8 @@ impl UsbBusImpl {
     pub(crate) fn ep_is_empty(&self, ep_addr: EndpointAddress) -> bool {
         let ep = self.epidx(ep_addr).borrow();
         match ep_addr.direction() {
-            UsbDirection::In => ep.write_done,
-            UsbDirection::Out => ep.read_ready,
+            UsbDirection::In => ep.write_len == 0,
+            UsbDirection::Out => ep.read_len == 0,
         }
     }
 
@@ -247,9 +262,12 @@ impl usb_device::bus::UsbBus for EmulatedUsbBus {
         })
     }
 
-    fn enable(&mut self) {}
+    fn enable(&mut self) {
+        info!("Bus: enable");
+    }
 
     fn force_reset(&self) -> UsbDeviceResult<()> {
+        info!("Bus: force reset not supported");
         Err(UsbError::Unsupported)
     }
 
@@ -280,7 +298,11 @@ impl usb_device::bus::UsbBus for EmulatedUsbBus {
             ep_in.write_done = false;
         }
 
-        // dbg!("WER", mask_in_complete, mask_ep_out, mask_ep_setup);
+        debug!(
+            "Bus: poll results: in: {:02x} out {:02x} setup {:02x}",
+            mask_in_complete, mask_ep_out, mask_ep_setup
+        );
+
         if mask_in_complete != 0 || mask_ep_out != 0 || mask_ep_setup != 0 {
             PollResult::Data {
                 ep_in_complete: mask_in_complete,
@@ -297,7 +319,13 @@ impl usb_device::bus::UsbBus for EmulatedUsbBus {
         let mut ep = io.epidx(ep_addr).borrow_mut();
         let len = min(buf.len(), min(ep.read_len, ep.max_size));
 
-        dbg!("read len from", buf.len(), len, ep_addr);
+        debug!(
+            "Bus: reading from EP {} {:#?} {} bytes into {} byte buffer",
+            ep_addr.index(),
+            ep_addr.direction(),
+            len,
+            buf.len()
+        );
 
         if len == 0 {
             return Err(UsbError::WouldBlock);
@@ -318,18 +346,22 @@ impl usb_device::bus::UsbBus for EmulatedUsbBus {
     }
 
     fn reset(&self) {
+        info!("Bus: reset");
         todo!()
     }
 
     fn resume(&self) {
+        info!("Bus: resume");
         todo!()
     }
 
     fn suspend(&self) {
+        info!("Bus: suspend");
         todo!()
     }
 
     fn set_device_address(&self, addr: u8) {
+        debug!("Bus: set device address: {}", addr);
         self.usb_address.replace(addr);
     }
 
@@ -351,9 +383,12 @@ impl usb_device::bus::UsbBus for EmulatedUsbBus {
         let offset = ep.write_len;
         let mut len = 0;
 
-        dbg!("write", buf.len());
-
         if buf.len() > ep.max_size {
+            debug!(
+                "Bus: EP {} {:#?} buffer overflow",
+                ep_addr.index(),
+                ep_addr.direction()
+            );
             return Err(UsbError::BufferOverflow);
         }
 
@@ -365,7 +400,13 @@ impl usb_device::bus::UsbBus for EmulatedUsbBus {
             len += 1;
         }
 
-        dbg!("wrote", len);
+        debug!(
+            "Bus: wrote to EP {} {:#?} {} bytes",
+            ep_addr.index(),
+            ep_addr.direction(),
+            len
+        );
+
         ep.write_len += len;
         ep.write_done = false;
         Ok(len)