diff --git a/exercise-book/src/nrf52-usb-getting-device-configured.md b/exercise-book/src/nrf52-usb-getting-device-configured.md index f9a0fa5d..c670e675 100644 --- a/exercise-book/src/nrf52-usb-getting-device-configured.md +++ b/exercise-book/src/nrf52-usb-getting-device-configured.md @@ -49,59 +49,58 @@ NOTE: On Windows, you may get a `GET_STATUS` request *before* the `SET_CONFIGURA ## Expected output -✅ Run the progam and check the log output. +✅ Run the program and check the log output. Once you are correctly handling the `SET_CONFIGURATION` request you should get logs like these: -```console -INFO:usb_5 -- USB: UsbReset @ 397.15576ms -INFO:usb_5 -- USB reset condition detected -INFO:usb_5 -- USB: UsbEp0Setup @ 470.00122ms -INFO:usb_5 -- EP0: GetDescriptor { descriptor: Device, length: 64 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_5 -- USB: UsbEp0DataDone @ 470.306395ms -INFO:usb_5 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_5 -- USB: UsbReset @ 520.721433ms -INFO:usb_5 -- USB reset condition detected -INFO:usb_5 -- USB: UsbEp0Setup @ 593.292235ms -INFO:usb_5 -- EP0: SetAddress { address: Some(21) } -INFO:usb_5 -- USB: UsbEp0Setup @ 609.954832ms -INFO:usb_5 -- EP0: GetDescriptor { descriptor: Device, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_5 -- USB: UsbEp0DataDone @ 610.260008ms -INFO:usb_5 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_5 -- USB: UsbEp0Setup @ 610.443113ms -INFO:usb_5 -- EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } -WARN:usb_5 -- EP0IN: stalled -INFO:usb_5 -- USB: UsbEp0Setup @ 610.809325ms -INFO:usb_5 -- EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } -WARN:usb_5 -- EP0IN: stalled -INFO:usb_5 -- USB: UsbEp0Setup @ 611.175535ms -INFO:usb_5 -- EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } -WARN:usb_5 -- EP0IN: stalled -INFO:usb_5 -- USB: UsbEp0Setup @ 611.511228ms -INFO:usb_5 -- EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 9 } -INFO:dk::usbd -- EP0IN: start 9B transfer -INFO:usb_5 -- USB: UsbEp0DataDone @ 611.846922ms -INFO:usb_5 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_5 -- USB: UsbEp0Setup @ 612.030027ms -INFO:usb_5 -- EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_5 -- USB: UsbEp0DataDone @ 612.365721ms -INFO:usb_5 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_5 -- USB: UsbEp0Setup @ 612.640378ms -INFO:usb_5 -- EP0: SetConfiguration { value: Some(42) } -INFO:usb_5 -- entering the configured state +```text +[DEBUG] Initializing the board (dk dk/src/lib.rs:312) +[DEBUG] Clocks configured (dk dk/src/lib.rs:330) +[DEBUG] RTC started (dk dk/src/lib.rs:349) +[DEBUG] I/O pins have been configured for digital output (dk dk/src/lib.rs:359) +[DEBUG] USB: UsbReset @ 00:00:00.324523 (usb_5 src/bin/usb-5.rs:56) +[WARN ] USB reset condition detected (usb_5 src/bin/usb-5.rs:60) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.367462 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 5, wlength: 0, windex: 0x0000, wvalue: 0x000b (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: SetAddress { address: Some(11) } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.370758 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 8, windex: 0x0000, wvalue: 0x0100 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 8 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 8B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.371337 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.371917 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 18, windex: 0x0000, wvalue: 0x0100 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 18 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.372497 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.373046 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 9, windex: 0x0000, wvalue: 0x0200 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 9 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 9B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.373748 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.373901 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 18, windex: 0x0000, wvalue: 0x0200 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 18 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.374603 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.379211 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 9, wlength: 0, windex: 0x0000, wvalue: 0x002a (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: SetConfiguration { value: Some(42) } (usb_5 src/bin/usb-5.rs:99) +[INFO ] entering the configured state (usb_5 src/bin/usb-5.rs:198) ``` These logs are from a Linux host. You can find traces for other OSes in these files (they are in the [`nrf52-code/usb-app-solutions/traces`](../../nrf52-code/usb-app-solutions/traces) folder): -- `linux-configured.txt` (same logs as the ones shown above) +- `linux-configured.txt` - `win-configured.txt`, this file only contains the logs produced by running `cargo xtask usb-descriptors` -- `macos-configured.txt` +- `macos-configured.txt` (same logs as the ones shown above) You can find a solution to this part of the exercise in [`nrf52-code/usb-app-solutions/src/bin/usb-5.rs`](../../nrf52-code/usb-app-solutions/src/bin/usb-5.rs). diff --git a/exercise-book/src/nrf52-usb-idle-state.md b/exercise-book/src/nrf52-usb-idle-state.md index 2b160edb..b1f75fd7 100644 --- a/exercise-book/src/nrf52-usb-idle-state.md +++ b/exercise-book/src/nrf52-usb-idle-state.md @@ -3,67 +3,61 @@ Once you have handled all the previously covered requests the device should be enumerated and remain idle awaiting for a new host request. Your logs may look like this: ```console -INFO:usb_4 -- USB: UsbReset @ 318.66455ms -INFO:usb_4 -- USB reset condition detected -INFO:usb_4 -- USB: UsbEp0Setup @ 391.418456ms -INFO:usb_4 -- EP0: GetDescriptor { descriptor: Device, length: 64 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_4 -- USB: UsbEp0DataDone @ 391.723632ms -INFO:usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_4 -- USB: UsbReset @ 442.016601ms -INFO:usb_4 -- USB reset condition detected -INFO:usb_4 -- USB: UsbEp0Setup @ 514.709471ms -INFO:usb_4 -- EP0: SetAddress { address: Some(17) } -INFO:usb_4 -- USB: UsbEp0Setup @ 531.37207ms -INFO:usb_4 -- EP0: GetDescriptor { descriptor: Device, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_4 -- USB: UsbEp0DataDone @ 531.646727ms -INFO:usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_4 -- USB: UsbEp0Setup @ 531.829832ms -INFO:usb_4 -- EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } -ERROR:usb_4 -- EP0IN: unexpected request; stalling the endpoint -INFO:usb_4 -- USB: UsbEp0Setup @ 532.226562ms -INFO:usb_4 -- EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } -ERROR:usb_4 -- EP0IN: unexpected request; stalling the endpoint -INFO:usb_4 -- USB: UsbEp0Setup @ 532.592772ms -INFO:usb_4 -- EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } -ERROR:usb_4 -- EP0IN: unexpected request; stalling the endpoint -INFO:usb_4 -- USB: UsbEp0Setup @ 533.020018ms -INFO:usb_4 -- EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 9 } -INFO:dk::usbd -- EP0IN: start 9B transfer -INFO:usb_4 -- USB: UsbEp0DataDone @ 533.386228ms -INFO:usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_4 -- USB: UsbEp0Setup @ 533.569335ms -INFO:usb_4 -- EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_4 -- USB: UsbEp0DataDone @ 533.935546ms -INFO:usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_4 -- USB: UsbEp0Setup @ 534.118651ms -INFO:usb_4 -- EP0: SetConfiguration { value: Some(42) } -ERROR:usb_4 -- EP0IN: unexpected request; stalling the endpoint +[DEBUG] USB: UsbReset @ 00:00:00.347259 (usb_4 src/bin/usb-4.rs:56) +[WARN ] USB reset condition detected (usb_4 src/bin/usb-4.rs:60) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.389770 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 5, wlength: 0, windex: 0x0000, wvalue: 0x000a (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: SetAddress { address: Some(10) } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.393066 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 8, windex: 0x0000, wvalue: 0x0100 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 8 } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] EP0IN: start 8B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.393585 (usb_4 src/bin/usb-4.rs:56) +[INFO ] EP0IN: transfer complete (usb_4 src/bin/usb-4.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.394409 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 18, windex: 0x0000, wvalue: 0x0100 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 18 } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.394958 (usb_4 src/bin/usb-4.rs:56) +[INFO ] EP0IN: transfer complete (usb_4 src/bin/usb-4.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.395385 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 9, windex: 0x0000, wvalue: 0x0200 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 9 } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] EP0IN: start 9B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.396057 (usb_4 src/bin/usb-4.rs:56) +[INFO ] EP0IN: transfer complete (usb_4 src/bin/usb-4.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.396270 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 18, windex: 0x0000, wvalue: 0x0200 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 18 } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.396942 (usb_4 src/bin/usb-4.rs:56) +[INFO ] EP0IN: transfer complete (usb_4 src/bin/usb-4.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.401824 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 9, wlength: 0, windex: 0x0000, wvalue: 0x002a (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: SetConfiguration { value: Some(42) } (usb_4 src/bin/usb-4.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_4 src/bin/usb-4.rs:71) ``` -Note that these logs are from a Linux host where a `SET_CONFIGURATION` request is sent after the `SET_ADDRESS` request. On other OSes you may not get that request before the bus goes idle. Also note that there are some `GET_DESCRIPTOR DeviceQualifier` requests in this case; you do not need to parse them in the `usb` crate as they'll be rejected (stalled) anyways. +Note that these logs are from a macOS host where a `SET_ADDRESS` request is sent first, and then a `GET_DESCRIPTOR` request. On other OSes the messages may be in a different order. Also note that there are some `GET_DESCRIPTOR DeviceQualifier` requests in this case; you do not need to parse them in the `usb` crate as they'll be rejected (stalled) anyways. You can find traces for other OSes in these files (they are in the [`nrf52-code/usb-app-solutions/traces`](../../nrf52-code/usb-app-solutions/traces) folder): -- `linux-enumeration.txt` (same logs as the ones shown above) -- `macos-enumeration.txt` +- `linux-enumeration.txt` +- `macos-enumeration.txt` (same logs as the ones shown above) - `win-enumeration.txt` -✅ Double check that the enumeration works by running [`cyme`](./nrf52-usb-listing-usb-devices.md) while `usb-4.rs` is running. +✅ Double check that the enumeration works by running `cargo xtask usb-list`](./nrf52-tools.md) while `usb-4.rs` is running. ```console -$ cyme +$ cargo xtask usb-list (...) random other USB devices will be listed - 2 15  0x1366 0x1051 J-Link 001050255503 12.0 Mb/s - 2 16  0x1209 0x0717 composite_device - 12.0 Mb/s +Bus 004 Device 001: ID 1209:0717 <-- nRF52840 on the nRF52840 Development Kit ``` -Both the J-Link and the device implemented by your firmware should appear in the list. +You can also try `cyme`, but we've found that on Windows, the device may not appear in the tool's output. Possibly this is because it's only showing devices which have accepted a Configuration. You can find a working solution up to this point in [`nrf52-code/usb-app-solutions/src/bin/usb-4.rs`](../../nrf52-code/usb-app-solutions/src/bin/usb-4.rs). Note that the solution uses the `usb2` crate to parse SETUP packets and that crate supports parsing all standard requests. diff --git a/nrf52-code/boards/dk-solution/src/usbd.rs b/nrf52-code/boards/dk-solution/src/usbd.rs index 41dd4ea4..603ba93b 100644 --- a/nrf52-code/boards/dk-solution/src/usbd.rs +++ b/nrf52-code/boards/dk-solution/src/usbd.rs @@ -56,7 +56,7 @@ impl Ep0In { self.busy = true; - defmt::println!("EP0IN: start {}B transfer", n); + defmt::debug!("EP0IN: start {}B transfer", n); // start DMA transfer dma_start(); @@ -80,7 +80,7 @@ impl Ep0In { usbd.events_ep0datadone.reset(); self.busy = false; - defmt::println!("EP0IN: transfer done"); + defmt::info!("EP0IN: transfer done"); } } } @@ -115,7 +115,7 @@ pub fn init(power: POWER, usbd: &USBD) { // wait until the USB cable has been connected while power.events_usbdetected.read().bits() == 0 { if once { - defmt::println!("waiting for USB connection on port J3"); + defmt::info!("waiting for USB connection on port J3"); once = false; } diff --git a/nrf52-code/boards/dk/src/usbd.rs b/nrf52-code/boards/dk/src/usbd.rs index 41dd4ea4..603ba93b 100644 --- a/nrf52-code/boards/dk/src/usbd.rs +++ b/nrf52-code/boards/dk/src/usbd.rs @@ -56,7 +56,7 @@ impl Ep0In { self.busy = true; - defmt::println!("EP0IN: start {}B transfer", n); + defmt::debug!("EP0IN: start {}B transfer", n); // start DMA transfer dma_start(); @@ -80,7 +80,7 @@ impl Ep0In { usbd.events_ep0datadone.reset(); self.busy = false; - defmt::println!("EP0IN: transfer done"); + defmt::info!("EP0IN: transfer done"); } } } @@ -115,7 +115,7 @@ pub fn init(power: POWER, usbd: &USBD) { // wait until the USB cable has been connected while power.events_usbdetected.read().bits() == 0 { if once { - defmt::println!("waiting for USB connection on port J3"); + defmt::info!("waiting for USB connection on port J3"); once = false; } diff --git a/nrf52-code/hal-app/src/bin/blinky.rs b/nrf52-code/hal-app/src/bin/blinky.rs index 483cf388..6153f2f7 100644 --- a/nrf52-code/hal-app/src/bin/blinky.rs +++ b/nrf52-code/hal-app/src/bin/blinky.rs @@ -19,7 +19,7 @@ fn main() -> ! { for _ in 0..10 { led.toggle(); timer.wait(Duration::from_secs(1)); - defmt::println!("LED toggled @ {=u64:tus}", dk::uptime_us()); + defmt::debug!("LED toggled @ {=u64:tus}", dk::uptime_us()); } dk::exit() diff --git a/nrf52-code/radio-app/src/bin/blinky.rs b/nrf52-code/radio-app/src/bin/blinky.rs index 5bb29659..3a1f6bec 100644 --- a/nrf52-code/radio-app/src/bin/blinky.rs +++ b/nrf52-code/radio-app/src/bin/blinky.rs @@ -19,7 +19,7 @@ fn main() -> ! { for _ in 0..10 { led.toggle(); timer.wait(Duration::from_secs(1)); - defmt::println!("LED toggled @ {=u64:tus}", dk::uptime_us()); + defmt::debug!("LED toggled @ {=u64:tus}", dk::uptime_us()); } dk::exit() diff --git a/nrf52-code/usb-app-solutions/src/bin/usb-1.rs b/nrf52-code/usb-app-solutions/src/bin/usb-1.rs index dbae90dd..d2702075 100644 --- a/nrf52-code/usb-app-solutions/src/bin/usb-1.rs +++ b/nrf52-code/usb-app-solutions/src/bin/usb-1.rs @@ -42,7 +42,7 @@ mod app { } fn on_event(_usbd: &USBD, event: Event) { - defmt::println!("USB: {} @ {}", event, dk::uptime()); + defmt::debug!("USB: {} @ {=u64:tus}", event, dk::uptime_us()); match event { Event::UsbReset => { diff --git a/nrf52-code/usb-app-solutions/src/bin/usb-2.rs b/nrf52-code/usb-app-solutions/src/bin/usb-2.rs index 58fab8ed..f64ceaab 100644 --- a/nrf52-code/usb-app-solutions/src/bin/usb-2.rs +++ b/nrf52-code/usb-app-solutions/src/bin/usb-2.rs @@ -40,7 +40,7 @@ mod app { } fn on_event(usbd: &USBD, event: Event) { - defmt::println!("USB: {} @ {}", event, dk::uptime()); + defmt::debug!("USB: {} @ {=u64:tus}", event, dk::uptime_us()); match event { Event::UsbReset => { @@ -75,8 +75,8 @@ mod app { // let windex = usbd::windex(usbd); // let wvalue = usbd::wvalue(usbd); - defmt::println!( - "SETUP: bmrequesttype: {}, brequest: {}, wlength: {}, windex: {}, wvalue: {}", + defmt::debug!( + "SETUP: bmrequesttype: 0b{=u8:08b}, brequest: {=u8}, wlength: {=u16}, windex: 0x{=u16:04x}, wvalue: 0x{=u16:04x}", bmrequesttype, brequest, wlength, @@ -90,7 +90,7 @@ mod app { Request::GetDescriptor { descriptor, length } if descriptor == Descriptor::Device => { - defmt::println!("GET_DESCRIPTOR Device [length={}]", length); + defmt::info!("GET_DESCRIPTOR Device [length={}]", length); defmt::println!("Goal reached; move to the next section"); dk::exit() diff --git a/nrf52-code/usb-app-solutions/src/bin/usb-3.rs b/nrf52-code/usb-app-solutions/src/bin/usb-3.rs index 1f566675..08cc7965 100644 --- a/nrf52-code/usb-app-solutions/src/bin/usb-3.rs +++ b/nrf52-code/usb-app-solutions/src/bin/usb-3.rs @@ -47,7 +47,7 @@ mod app { } fn on_event(usbd: &USBD, ep0in: &mut Ep0In, event: Event) { - defmt::println!("USB: {} @ {}", event, dk::uptime()); + defmt::debug!("USB: {} @ {=u64:tus}", event, dk::uptime_us()); match event { Event::UsbReset => { @@ -63,8 +63,8 @@ mod app { let windex = usbd::windex(usbd); let wvalue = usbd::wvalue(usbd); - defmt::println!( - "SETUP: bmrequesttype: {}, brequest: {}, wlength: {}, windex: {}, wvalue: {}", + defmt::debug!( + "SETUP: bmrequesttype: 0b{=u8:08b}, brequest: {=u8}, wlength: {=u16}, windex: 0x{=u16:04x}, wvalue: 0x{=u16:04x}", bmrequesttype, brequest, wlength, @@ -79,7 +79,7 @@ mod app { Request::GetDescriptor { descriptor, length } if descriptor == Descriptor::Device => { - defmt::println!("GET_DESCRIPTOR Device [length={}]", length); + defmt::info!("GET_DESCRIPTOR Device [length={}]", length); let desc = usb2::device::Descriptor { bDeviceClass: 0, diff --git a/nrf52-code/usb-app-solutions/src/bin/usb-4.rs b/nrf52-code/usb-app-solutions/src/bin/usb-4.rs index 24d25f88..c7211bf2 100644 --- a/nrf52-code/usb-app-solutions/src/bin/usb-4.rs +++ b/nrf52-code/usb-app-solutions/src/bin/usb-4.rs @@ -53,16 +53,16 @@ mod app { } fn on_event(usbd: &USBD, ep0in: &mut Ep0In, state: &mut State, event: Event) { - defmt::println!("USB: {} @ {}", event, dk::uptime()); + defmt::debug!("USB: {} @ {=u64:tus}", event, dk::uptime_us()); match event { Event::UsbReset => { - defmt::println!("USB reset condition detected"); + defmt::warn!("USB reset condition detected"); *state = State::Default; } Event::UsbEp0DataDone => { - defmt::println!("EP0IN: transfer complete"); + defmt::info!("EP0IN: transfer complete"); ep0in.end(usbd); } @@ -85,8 +85,8 @@ mod app { let windex = usbd::windex(usbd); let wvalue = usbd::wvalue(usbd); - defmt::println!( - "bmrequesttype: {}, brequest: {}, wlength: {}, windex: {}, wvalue: {}", + defmt::debug!( + "SETUP: bmrequesttype: 0b{=u8:08b}, brequest: {=u8}, wlength: {=u16}, windex: 0x{=u16:04x}, wvalue: 0x{=u16:04x}", bmrequesttype, brequest, wlength, @@ -96,9 +96,9 @@ mod app { let request = Request::parse(bmrequesttype, brequest, wvalue, windex, wlength) .expect("Error parsing request"); - defmt::println!("EP0: {}", defmt::Debug2Format(&request)); + defmt::info!("EP0: {}", defmt::Debug2Format(&request)); // ^^^^^^^^^^^^^^^^^^^ this adapter is currently needed to log - // `StandardRequest` with `defmt` + // `Request` with `defmt` match request { // section 9.4.3 // this request is valid in any state diff --git a/nrf52-code/usb-app-solutions/src/bin/usb-5.rs b/nrf52-code/usb-app-solutions/src/bin/usb-5.rs index 888b300d..cee1b2b3 100644 --- a/nrf52-code/usb-app-solutions/src/bin/usb-5.rs +++ b/nrf52-code/usb-app-solutions/src/bin/usb-5.rs @@ -53,16 +53,16 @@ mod app { } fn on_event(usbd: &USBD, ep0in: &mut Ep0In, state: &mut State, event: Event) { - defmt::println!("USB: {} @ {}", event, dk::uptime()); + defmt::debug!("USB: {} @ {=u64:tus}", event, dk::uptime_us()); match event { Event::UsbReset => { - defmt::println!("USB reset condition detected"); + defmt::warn!("USB reset condition detected"); *state = State::Default; } Event::UsbEp0DataDone => { - defmt::println!("EP0IN: transfer complete"); + defmt::info!("EP0IN: transfer complete"); ep0in.end(usbd); } @@ -85,8 +85,8 @@ mod app { let windex = usbd::windex(usbd); let wvalue = usbd::wvalue(usbd); - defmt::println!( - "bmrequesttype: {}, brequest: {}, wlength: {}, windex: {}, wvalue: {}", + defmt::debug!( + "SETUP: bmrequesttype: 0b{=u8:08b}, brequest: {=u8}, wlength: {=u16}, windex: 0x{=u16:04x}, wvalue: 0x{=u16:04x}", bmrequesttype, brequest, wlength, @@ -96,9 +96,9 @@ mod app { let request = Request::parse(bmrequesttype, brequest, wvalue, windex, wlength) .expect("Error parsing request"); - defmt::println!("EP0: {}", defmt::Debug2Format(&request)); + defmt::info!("EP0: {}", defmt::Debug2Format(&request)); // ^^^^^^^^^^^^^^^^^^^ this adapter is currently needed to log - // `StandardRequest` with `defmt` + // `Request` with `defmt` match request { // section 9.4.3 @@ -195,7 +195,7 @@ mod app { State::Address(address) => { if let Some(value) = value { if value.get() == CONFIG_VAL { - defmt::println!("entering the configured state"); + defmt::info!("entering the configured state"); *state = State::Configured { address, value }; } else { defmt::error!("unsupported configuration value"); diff --git a/nrf52-code/usb-app-solutions/traces/linux-configured.txt b/nrf52-code/usb-app-solutions/traces/linux-configured.txt index 2eaaba35..fe37e763 100644 --- a/nrf52-code/usb-app-solutions/traces/linux-configured.txt +++ b/nrf52-code/usb-app-solutions/traces/linux-configured.txt @@ -1,42 +1,52 @@ -INFO:usb_5 -- USB: UsbReset @ 397.15576ms -INFO:usb_5 -- USB reset condition detected -INFO:usb_5 -- USB: UsbEp0Setup @ 470.00122ms -INFO:usb_5 -- EP0: GetDescriptor { descriptor: Device, length: 64 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_5 -- USB: UsbEp0DataDone @ 470.306395ms -INFO:usb_5 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_5 -- USB: UsbReset @ 520.721433ms -INFO:usb_5 -- USB reset condition detected -INFO:usb_5 -- USB: UsbEp0Setup @ 593.292235ms -INFO:usb_5 -- EP0: SetAddress { address: Some(21) } -INFO:usb_5 -- USB: UsbEp0Setup @ 609.954832ms -INFO:usb_5 -- EP0: GetDescriptor { descriptor: Device, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_5 -- USB: UsbEp0DataDone @ 610.260008ms -INFO:usb_5 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_5 -- USB: UsbEp0Setup @ 610.443113ms -INFO:usb_5 -- EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } -WARN:usb_5 -- EP0IN: stalled -INFO:usb_5 -- USB: UsbEp0Setup @ 610.809325ms -INFO:usb_5 -- EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } -WARN:usb_5 -- EP0IN: stalled -INFO:usb_5 -- USB: UsbEp0Setup @ 611.175535ms -INFO:usb_5 -- EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } -WARN:usb_5 -- EP0IN: stalled -INFO:usb_5 -- USB: UsbEp0Setup @ 611.511228ms -INFO:usb_5 -- EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 9 } -INFO:dk::usbd -- EP0IN: start 9B transfer -INFO:usb_5 -- USB: UsbEp0DataDone @ 611.846922ms -INFO:usb_5 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_5 -- USB: UsbEp0Setup @ 612.030027ms -INFO:usb_5 -- EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_5 -- USB: UsbEp0DataDone @ 612.365721ms -INFO:usb_5 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_5 -- USB: UsbEp0Setup @ 612.640378ms -INFO:usb_5 -- EP0: SetConfiguration { value: Some(42) } -INFO:usb_5 -- entering the configured state +[DEBUG] Initializing the board (dk dk/src/lib.rs:312) +[DEBUG] Clocks configured (dk dk/src/lib.rs:330) +[DEBUG] RTC started (dk dk/src/lib.rs:349) +[DEBUG] I/O pins have been configured for digital output (dk dk/src/lib.rs:359) +[DEBUG] USB: UsbReset @ 00:00:00.196411 (usb_5 src/bin/usb-5.rs:56) +[WARN ] USB reset condition detected (usb_5 src/bin/usb-5.rs:60) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.239105 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 5, wlength: 0, windex: 0x0000, wvalue: 0x000b (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: SetAddress { address: Some(11) } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.242248 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 8, windex: 0x0000, wvalue: 0x0100 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 8 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 8B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.242797 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.243377 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 18, windex: 0x0000, wvalue: 0x0100 (usb_5 src/bin/usb-5.rs:88) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.243927 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.244232 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 9, windex: 0x0000, wvalue: 0x0200 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 9 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 9B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.244903 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.245056 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 18, windex: 0x0000, wvalue: 0x0200 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 18 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.245819 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.253479 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 9, wlength: 0, windex: 0x0000, wvalue: 0x002a (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: SetConfiguration { value: Some(42) } (usb_5 src/bin/usb-5.rs:99) +[INFO ] entering the configured state (usb_5 src/bin/usb-5.rs:198) +[DEBUG] USB: UsbEp0Setup @ 00:00:04.825073 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 10, windex: 0x0000, wvalue: 0x0600 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } (usb_5 src/bin/usb-5.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_5 src/bin/usb-5.rs:71) +[DEBUG] USB: UsbEp0Setup @ 00:00:04.827301 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 10, windex: 0x0000, wvalue: 0x0600 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } (usb_5 src/bin/usb-5.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_5 src/bin/usb-5.rs:71) +[DEBUG] USB: UsbEp0Setup @ 00:00:04.828948 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 10, windex: 0x0000, wvalue: 0x0600 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } (usb_5 src/bin/usb-5.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_5 src/bin/usb-5.rs:71) diff --git a/nrf52-code/usb-app-solutions/traces/linux-enumeration.txt b/nrf52-code/usb-app-solutions/traces/linux-enumeration.txt index 89c900c3..63dd68b1 100644 --- a/nrf52-code/usb-app-solutions/traces/linux-enumeration.txt +++ b/nrf52-code/usb-app-solutions/traces/linux-enumeration.txt @@ -1,42 +1,73 @@ -INFO:usb_4 -- USB: UsbReset @ 318.66455ms -INFO:usb_4 -- USB reset condition detected -INFO:usb_4 -- USB: UsbEp0Setup @ 391.418456ms -INFO:usb_4 -- EP0: GetDescriptor { descriptor: Device, length: 64 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_4 -- USB: UsbEp0DataDone @ 391.723632ms -INFO:usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_4 -- USB: UsbReset @ 442.016601ms -INFO:usb_4 -- USB reset condition detected -INFO:usb_4 -- USB: UsbEp0Setup @ 514.709471ms -INFO:usb_4 -- EP0: SetAddress { address: Some(17) } -INFO:usb_4 -- USB: UsbEp0Setup @ 531.37207ms -INFO:usb_4 -- EP0: GetDescriptor { descriptor: Device, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_4 -- USB: UsbEp0DataDone @ 531.646727ms -INFO:usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_4 -- USB: UsbEp0Setup @ 531.829832ms -INFO:usb_4 -- EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } -ERROR:usb_4 -- EP0IN: unexpected request; stalling the endpoint -INFO:usb_4 -- USB: UsbEp0Setup @ 532.226562ms -INFO:usb_4 -- EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } -ERROR:usb_4 -- EP0IN: unexpected request; stalling the endpoint -INFO:usb_4 -- USB: UsbEp0Setup @ 532.592772ms -INFO:usb_4 -- EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } -ERROR:usb_4 -- EP0IN: unexpected request; stalling the endpoint -INFO:usb_4 -- USB: UsbEp0Setup @ 533.020018ms -INFO:usb_4 -- EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 9 } -INFO:dk::usbd -- EP0IN: start 9B transfer -INFO:usb_4 -- USB: UsbEp0DataDone @ 533.386228ms -INFO:usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_4 -- USB: UsbEp0Setup @ 533.569335ms -INFO:usb_4 -- EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_4 -- USB: UsbEp0DataDone @ 533.935546ms -INFO:usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_4 -- USB: UsbEp0Setup @ 534.118651ms -INFO:usb_4 -- EP0: SetConfiguration { value: Some(42) } -ERROR:usb_4 -- EP0IN: unexpected request; stalling the endpoint +[DEBUG] Initializing the board (dk dk/src/lib.rs:312) +[DEBUG] Clocks configured (dk dk/src/lib.rs:330) +[DEBUG] RTC started (dk dk/src/lib.rs:349) +[DEBUG] I/O pins have been configured for digital output (dk dk/src/lib.rs:359) +[DEBUG] USB: UsbReset @ 00:00:00.148071 (usb_4 src/bin/usb-4.rs:56) +[WARN ] USB reset condition detected (usb_4 src/bin/usb-4.rs:60) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.190612 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 5, wlength: 0, windex: 0x0000, wvalue: 0x000b (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: SetAddress { address: Some(11) } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.193878 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 8, windex: 0x0000, wvalue: 0x0100 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 8 } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] EP0IN: start 8B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.194427 (usb_4 src/bin/usb-4.rs:56) +[INFO ] EP0IN: transfer complete (usb_4 src/bin/usb-4.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.194976 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 18, windex: 0x0000, wvalue: 0x0100 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 18 } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.195617 (usb_4 src/bin/usb-4.rs:56) +[INFO ] EP0IN: transfer complete (usb_4 src/bin/usb-4.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.195861 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 9, windex: 0x0000, wvalue: 0x0200 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 9 } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] EP0IN: start 9B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.196533 (usb_4 src/bin/usb-4.rs:56) +[INFO ] EP0IN: transfer complete (usb_4 src/bin/usb-4.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.196777 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 18, windex: 0x0000, wvalue: 0x0200 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 18 } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.197448 (usb_4 src/bin/usb-4.rs:56) +[INFO ] EP0IN: transfer complete (usb_4 src/bin/usb-4.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.201904 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 9, wlength: 0, windex: 0x0000, wvalue: 0x002a (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: SetConfiguration { value: Some(42) } (usb_4 src/bin/usb-4.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_4 src/bin/usb-4.rs:71) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.304077 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 9, wlength: 0, windex: 0x0000, wvalue: 0x002a (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: SetConfiguration { value: Some(42) } (usb_4 src/bin/usb-4.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_4 src/bin/usb-4.rs:71) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.406646 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 9, wlength: 0, windex: 0x0000, wvalue: 0x002a (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: SetConfiguration { value: Some(42) } (usb_4 src/bin/usb-4.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_4 src/bin/usb-4.rs:71) +[DEBUG] USB: UsbEp0Setup @ 00:00:04.554229 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 10, windex: 0x0000, wvalue: 0x0600 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } (usb_4 src/bin/usb-4.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_4 src/bin/usb-4.rs:71) +[DEBUG] USB: UsbEp0Setup @ 00:00:04.557098 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 10, windex: 0x0000, wvalue: 0x0600 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } (usb_4 src/bin/usb-4.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_4 src/bin/usb-4.rs:71) +[DEBUG] USB: UsbEp0Setup @ 00:00:04.558868 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 10, windex: 0x0000, wvalue: 0x0600 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } (usb_4 src/bin/usb-4.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_4 src/bin/usb-4.rs:71) +[DEBUG] USB: UsbEp0Setup @ 00:00:04.561523 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 9, wlength: 0, windex: 0x0000, wvalue: 0x002a (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: SetConfiguration { value: Some(42) } (usb_4 src/bin/usb-4.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_4 src/bin/usb-4.rs:71) +[DEBUG] USB: UsbEp0Setup @ 00:00:04.664123 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 9, wlength: 0, windex: 0x0000, wvalue: 0x002a (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: SetConfiguration { value: Some(42) } (usb_4 src/bin/usb-4.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_4 src/bin/usb-4.rs:71) +[DEBUG] USB: UsbEp0Setup @ 00:00:04.767517 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 9, wlength: 0, windex: 0x0000, wvalue: 0x002a (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: SetConfiguration { value: Some(42) } (usb_4 src/bin/usb-4.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_4 src/bin/usb-4.rs:71) diff --git a/nrf52-code/usb-app-solutions/traces/macos-configured.txt b/nrf52-code/usb-app-solutions/traces/macos-configured.txt index d30ff2c5..4f11bb66 100644 --- a/nrf52-code/usb-app-solutions/traces/macos-configured.txt +++ b/nrf52-code/usb-app-solutions/traces/macos-configured.txt @@ -1,31 +1,41 @@ -INFO:usb_5_solution -- USB: UsbReset @ 101.104735ms -INFO:usb_5_solution -- USB reset condition detected -INFO:usb_5_solution -- USB: UsbEp0Setup @ 166.68701ms -INFO:usb_5_solution -- EP0: SetAddress { address: Some(21) } -INFO:usb_5_solution -- USB: UsbEp0Setup @ 168.853758ms -INFO:usb_5_solution -- EP0: GetDescriptor { descriptor: Device, length: 8 } -INFO:dk::usbd -- EP0IN: start 8B transfer -INFO:usb_5_solution -- USB: UsbEp0DataDone @ 169.128416ms -INFO:usb_5_solution -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_5_solution -- USB: UsbEp0Setup @ 169.372557ms -INFO:usb_5_solution -- EP0: GetDescriptor { descriptor: Device, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_5_solution -- USB: UsbEp0DataDone @ 169.677733ms -INFO:usb_5_solution -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_5_solution -- USB: UsbEp0Setup @ 172.180175ms -INFO:usb_5_solution -- EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 9 } -INFO:dk::usbd -- EP0IN: start 9B transfer -INFO:usb_5_solution -- USB: UsbEp0DataDone @ 172.515868ms -INFO:usb_5_solution -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_5_solution -- USB: UsbEp0Setup @ 172.698972ms -INFO:usb_5_solution -- EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_5_solution -- USB: UsbEp0DataDone @ 173.00415ms -INFO:usb_5_solution -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_5_solution -- USB: UsbEp0Setup @ 237.945556ms -INFO:usb_5_solution -- EP0: SetConfiguration { value: Some(42) } -INFO:usb_5_solution -- entering the configured state +[DEBUG] Initializing the board (dk dk/src/lib.rs:312) +[DEBUG] Clocks configured (dk dk/src/lib.rs:330) +[DEBUG] RTC started (dk dk/src/lib.rs:349) +[DEBUG] I/O pins have been configured for digital output (dk dk/src/lib.rs:359) +[DEBUG] USB: UsbReset @ 00:00:00.324523 (usb_5 src/bin/usb-5.rs:56) +[WARN ] USB reset condition detected (usb_5 src/bin/usb-5.rs:60) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.367462 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 5, wlength: 0, windex: 0x0000, wvalue: 0x000b (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: SetAddress { address: Some(11) } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.370758 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 8, windex: 0x0000, wvalue: 0x0100 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 8 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 8B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.371337 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.371917 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 18, windex: 0x0000, wvalue: 0x0100 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 18 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.372497 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.373046 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 9, windex: 0x0000, wvalue: 0x0200 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 9 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 9B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.373748 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.373901 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 18, windex: 0x0000, wvalue: 0x0200 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 18 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.374603 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.379211 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 9, wlength: 0, windex: 0x0000, wvalue: 0x002a (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: SetConfiguration { value: Some(42) } (usb_5 src/bin/usb-5.rs:99) +[INFO ] entering the configured state (usb_5 src/bin/usb-5.rs:198) diff --git a/nrf52-code/usb-app-solutions/traces/macos-enumeration.txt b/nrf52-code/usb-app-solutions/traces/macos-enumeration.txt index 9a4945fa..35b5735e 100644 --- a/nrf52-code/usb-app-solutions/traces/macos-enumeration.txt +++ b/nrf52-code/usb-app-solutions/traces/macos-enumeration.txt @@ -1,37 +1,49 @@ -INFO:usb_4_solution -- USB: UsbReset @ 101.135252ms -INFO:usb_4_solution -- USB reset condition detected -INFO:usb_4_solution -- USB: UsbEp0Setup @ 166.625976ms -INFO:usb_4_solution -- EP0: SetAddress { address: Some(20) } -INFO:usb_4_solution -- USB: UsbEp0Setup @ 168.823241ms -INFO:usb_4_solution -- EP0: GetDescriptor { descriptor: Device, length: 8 } -INFO:dk::usbd -- EP0IN: start 8B transfer -INFO:usb_4_solution -- USB: UsbEp0DataDone @ 169.0979ms -INFO:usb_4_solution -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_4_solution -- USB: UsbEp0Setup @ 169.34204ms -INFO:usb_4_solution -- EP0: GetDescriptor { descriptor: Device, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_4_solution -- USB: UsbEp0DataDone @ 169.616697ms -INFO:usb_4_solution -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_4_solution -- USB: UsbEp0Setup @ 171.905516ms -INFO:usb_4_solution -- EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 9 } -INFO:dk::usbd -- EP0IN: start 9B transfer -INFO:usb_4_solution -- USB: UsbEp0DataDone @ 172.210691ms -INFO:usb_4_solution -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_4_solution -- USB: UsbEp0Setup @ 172.393797ms -INFO:usb_4_solution -- EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:usb_4_solution -- USB: UsbEp0DataDone @ 172.729491ms -INFO:usb_4_solution -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:usb_4_solution -- USB: UsbEp0Setup @ 237.640378ms -INFO:usb_4_solution -- EP0: SetConfiguration { value: Some(42) } -WARN:usb_4_solution -- EP0IN: unexpected request; stalling the endpoint -INFO:usb_4_solution -- USB: UsbEp0Setup @ 338.012695ms -INFO:usb_4_solution -- EP0: SetConfiguration { value: Some(42) } -WARN:usb_4_solution -- EP0IN: unexpected request; stalling the endpoint -INFO:usb_4_solution -- USB: UsbEp0Setup @ 438.385008ms -INFO:usb_4_solution -- EP0: SetConfiguration { value: Some(42) } -WARN:usb_4_solution -- EP0IN: unexpected request; stalling the endpoint +[DEBUG] Initializing the board (dk dk/src/lib.rs:312) +[DEBUG] Clocks configured (dk dk/src/lib.rs:330) +[DEBUG] RTC started (dk dk/src/lib.rs:349) +[DEBUG] I/O pins have been configured for digital output (dk dk/src/lib.rs:359) +[DEBUG] USB: UsbReset @ 00:00:00.347259 (usb_4 src/bin/usb-4.rs:56) +[WARN ] USB reset condition detected (usb_4 src/bin/usb-4.rs:60) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.389770 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 5, wlength: 0, windex: 0x0000, wvalue: 0x000a (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: SetAddress { address: Some(10) } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.393066 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 8, windex: 0x0000, wvalue: 0x0100 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 8 } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] EP0IN: start 8B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.393585 (usb_4 src/bin/usb-4.rs:56) +[INFO ] EP0IN: transfer complete (usb_4 src/bin/usb-4.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.394409 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 18, windex: 0x0000, wvalue: 0x0100 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 18 } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.394958 (usb_4 src/bin/usb-4.rs:56) +[INFO ] EP0IN: transfer complete (usb_4 src/bin/usb-4.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.395385 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 9, windex: 0x0000, wvalue: 0x0200 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 9 } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] EP0IN: start 9B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.396057 (usb_4 src/bin/usb-4.rs:56) +[INFO ] EP0IN: transfer complete (usb_4 src/bin/usb-4.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.396270 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 18, windex: 0x0000, wvalue: 0x0200 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 18 } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.396942 (usb_4 src/bin/usb-4.rs:56) +[INFO ] EP0IN: transfer complete (usb_4 src/bin/usb-4.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.401824 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 9, wlength: 0, windex: 0x0000, wvalue: 0x002a (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: SetConfiguration { value: Some(42) } (usb_4 src/bin/usb-4.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_4 src/bin/usb-4.rs:71) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.505432 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 9, wlength: 0, windex: 0x0000, wvalue: 0x002a (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: SetConfiguration { value: Some(42) } (usb_4 src/bin/usb-4.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_4 src/bin/usb-4.rs:71) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.608215 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 9, wlength: 0, windex: 0x0000, wvalue: 0x002a (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: SetConfiguration { value: Some(42) } (usb_4 src/bin/usb-4.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_4 src/bin/usb-4.rs:71) diff --git a/nrf52-code/usb-app-solutions/traces/win-configured.txt b/nrf52-code/usb-app-solutions/traces/win-configured.txt index 31358b33..0a033944 100644 --- a/nrf52-code/usb-app-solutions/traces/win-configured.txt +++ b/nrf52-code/usb-app-solutions/traces/win-configured.txt @@ -1,42 +1,36 @@ -INFO:rtic_usb_4 -- USB: UsbReset @ 305.594085691s -INFO:rtic_usb_4 -- USB reset condition detected -INFO:rtic_usb_4 -- USB: UsbEp0Setup @ 305.681701658s -INFO:rtic_usb_4 -- EP0: GetDescriptor { descriptor: Device, length: 64 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:rtic_usb_4 -- USB: UsbEp0DataDone @ 305.682037352s -INFO:rtic_usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:rtic_usb_4 -- USB: UsbReset @ 305.682220457s -INFO:rtic_usb_4 -- USB reset condition detected -INFO:rtic_usb_4 -- USB: UsbEp0Setup @ 305.769470213s -INFO:rtic_usb_4 -- EP0: SetAddress { address: Some(7) } -INFO:rtic_usb_4 -- USB: UsbEp0Setup @ 305.780456541s -INFO:rtic_usb_4 -- EP0: GetDescriptor { descriptor: Device, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:rtic_usb_4 -- USB: UsbEp0DataDone @ 305.780761718s -INFO:rtic_usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:rtic_usb_4 -- USB: UsbEp0Setup @ 305.784606932s -INFO:rtic_usb_4 -- EP0: GetDescriptor { descriptor: Device, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:rtic_usb_4 -- USB: UsbEp0DataDone @ 305.784912108s -INFO:rtic_usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:rtic_usb_4 -- USB: UsbEp0Setup @ 305.785095213s -INFO:rtic_usb_4 -- EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 9 } -INFO:dk::usbd -- EP0IN: start 9B transfer -INFO:rtic_usb_4 -- USB: UsbEp0DataDone @ 305.78540039s -INFO:rtic_usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:rtic_usb_4 -- USB: UsbEp0Setup @ 305.785583495s -INFO:rtic_usb_4 -- EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:rtic_usb_4 -- USB: UsbEp0DataDone @ 305.785919188s -INFO:rtic_usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:rtic_usb_4 -- USB: UsbEp0Setup @ 305.786102293s -INFO:rtic_usb_4 -- EP0: GetStatus(Device) -WARN:rtic_usb_4 -- EP0IN: stalled -INFO:rtic_usb_4 -- USB: UsbEp0Setup @ 305.786621093s -INFO:rtic_usb_4 -- EP0: SetConfiguration { value: Some(42) } -INFO:rtic_usb_4 -- entering the configured stat +[DEBUG] Initializing the board (dk dk/src/lib.rs:312) +[DEBUG] Clocks configured (dk dk/src/lib.rs:330) +[DEBUG] RTC started (dk dk/src/lib.rs:349) +[DEBUG] I/O pins have been configured for digital output (dk dk/src/lib.rs:359) +[DEBUG] USB: UsbReset @ 00:00:00.101654 (usb_4 src/bin/usb-4.rs:56) +[WARN ] USB reset condition detected (usb_4 src/bin/usb-4.rs:60) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.184112 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 64, windex: 0x0000, wvalue: 0x0100 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 64 } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.185272 (usb_4 src/bin/usb-4.rs:56) +[INFO ] EP0IN: transfer complete (usb_4 src/bin/usb-4.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbReset @ 00:00:00.186340 (usb_4 src/bin/usb-4.rs:56) +[WARN ] USB reset condition detected (usb_4 src/bin/usb-4.rs:60) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.268707 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 5, wlength: 0, windex: 0x0000, wvalue: 0x0002 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: SetAddress { address: Some(2) } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.279815 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 18, windex: 0x0000, wvalue: 0x0100 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 18 } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.281250 (usb_4 src/bin/usb-4.rs:56) +[INFO ] EP0IN: transfer complete (usb_4 src/bin/usb-4.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.291351 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 255, windex: 0x0000, wvalue: 0x0200 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 255 } (usb_4 src/bin/usb-4.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.292266 (usb_4 src/bin/usb-4.rs:56) +[INFO ] EP0IN: transfer complete (usb_4 src/bin/usb-4.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.294281 (usb_4 src/bin/usb-4.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 10, windex: 0x0000, wvalue: 0x0600 (usb_4 src/bin/usb-4.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } (usb_4 src/bin/usb-4.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_4 src/bin/usb-4.rs:71) diff --git a/nrf52-code/usb-app-solutions/traces/win-enumeration.txt b/nrf52-code/usb-app-solutions/traces/win-enumeration.txt index 9429763f..cea851ed 100644 --- a/nrf52-code/usb-app-solutions/traces/win-enumeration.txt +++ b/nrf52-code/usb-app-solutions/traces/win-enumeration.txt @@ -1,27 +1,70 @@ -INFO:rtic_usb_4 -- USB: UsbReset @ 101.837157ms -INFO:rtic_usb_4 -- USB reset condition detected -INFO:rtic_usb_4 -- USB: UsbEp0Setup @ 190.216063ms -INFO:rtic_usb_4 -- EP0: GetDescriptor { descriptor: Device, length: 64 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:rtic_usb_4 -- USB: UsbEp0DataDone @ 190.551757ms -INFO:rtic_usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:rtic_usb_4 -- USB: UsbReset @ 190.734862ms -INFO:rtic_usb_4 -- USB reset condition detected -INFO:rtic_usb_4 -- USB: UsbEp0Setup @ 277.954101ms -INFO:rtic_usb_4 -- EP0: SetAddress { address: Some(6) } -INFO:rtic_usb_4 -- USB: UsbEp0Setup @ 288.940428ms -INFO:rtic_usb_4 -- EP0: GetDescriptor { descriptor: Device, length: 18 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:rtic_usb_4 -- USB: UsbEp0DataDone @ 289.245603ms -INFO:rtic_usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:rtic_usb_4 -- USB: UsbEp0Setup @ 296.783446ms -INFO:rtic_usb_4 -- EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 255 } -INFO:dk::usbd -- EP0IN: start 18B transfer -INFO:rtic_usb_4 -- USB: UsbEp0DataDone @ 297.11914ms -INFO:rtic_usb_4 -- EP0IN: transfer complete -INFO:dk::usbd -- EP0IN: transfer done -INFO:rtic_usb_4 -- USB: UsbEp0Setup @ 297.302245ms -INFO:rtic_usb_4 -- EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } -WARN:rtic_usb_4 -- EP0IN: stalled +[DEBUG] Initializing the board (dk dk/src/lib.rs:312) +[DEBUG] Clocks configured (dk dk/src/lib.rs:330) +[DEBUG] RTC started (dk dk/src/lib.rs:349) +[DEBUG] I/O pins have been configured for digital output (dk dk/src/lib.rs:359) +[DEBUG] USB: UsbReset @ 00:00:00.102142 (usb_5 src/bin/usb-5.rs:56) +[WARN ] USB reset condition detected (usb_5 src/bin/usb-5.rs:60) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.184967 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 64, windex: 0x0000, wvalue: 0x0100 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 64 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.185607 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbReset @ 00:00:00.186950 (usb_5 src/bin/usb-5.rs:56) +[WARN ] USB reset condition detected (usb_5 src/bin/usb-5.rs:60) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.270324 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 5, wlength: 0, windex: 0x0000, wvalue: 0x0002 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: SetAddress { address: Some(2) } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.281280 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 18, windex: 0x0000, wvalue: 0x0100 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 18 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.282623 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.288482 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 255, windex: 0x0000, wvalue: 0x0200 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 255 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:00:00.289611 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:00:00.291625 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 10, windex: 0x0000, wvalue: 0x0600 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } (usb_5 src/bin/usb-5.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_5 src/bin/usb-5.rs:71) +[DEBUG] USB: UsbReset @ 00:02:16.382995 (usb_5 src/bin/usb-5.rs:56) +[WARN ] USB reset condition detected (usb_5 src/bin/usb-5.rs:60) +[DEBUG] USB: UsbReset @ 00:02:21.911010 (usb_5 src/bin/usb-5.rs:56) +[WARN ] USB reset condition detected (usb_5 src/bin/usb-5.rs:60) +[DEBUG] USB: UsbEp0Setup @ 00:02:21.993957 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 64, windex: 0x0000, wvalue: 0x0100 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 64 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:02:21.994781 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbReset @ 00:02:21.995849 (usb_5 src/bin/usb-5.rs:56) +[WARN ] USB reset condition detected (usb_5 src/bin/usb-5.rs:60) +[DEBUG] USB: UsbEp0Setup @ 00:02:22.078247 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b00000000, brequest: 5, wlength: 0, windex: 0x0000, wvalue: 0x0002 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: SetAddress { address: Some(2) } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] USB: UsbEp0Setup @ 00:02:22.089233 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 18, windex: 0x0000, wvalue: 0x0100 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Device, length: 18 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:02:22.090789 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:02:22.097961 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 255, windex: 0x0000, wvalue: 0x0200 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: Configuration { index: 0 }, length: 255 } (usb_5 src/bin/usb-5.rs:99) +[DEBUG] EP0IN: start 18B transfer (dk dk/src/usbd.rs:59) +[DEBUG] USB: UsbEp0DataDone @ 00:02:22.098785 (usb_5 src/bin/usb-5.rs:56) +[INFO ] EP0IN: transfer complete (usb_5 src/bin/usb-5.rs:65) +[INFO ] EP0IN: transfer done (dk dk/src/usbd.rs:83) +[DEBUG] USB: UsbEp0Setup @ 00:02:22.100769 (usb_5 src/bin/usb-5.rs:56) +[DEBUG] SETUP: bmrequesttype: 0b10000000, brequest: 6, wlength: 10, windex: 0x0000, wvalue: 0x0600 (usb_5 src/bin/usb-5.rs:88) +[INFO ] EP0: GetDescriptor { descriptor: DeviceQualifier, length: 10 } (usb_5 src/bin/usb-5.rs:99) +[WARN ] EP0IN: unexpected request; stalling the endpoint (usb_5 src/bin/usb-5.rs:71) diff --git a/nrf52-code/usb-app/src/bin/usb-1.rs b/nrf52-code/usb-app/src/bin/usb-1.rs index f44f506e..4595c191 100644 --- a/nrf52-code/usb-app/src/bin/usb-1.rs +++ b/nrf52-code/usb-app/src/bin/usb-1.rs @@ -42,7 +42,7 @@ mod app { } fn on_event(_usbd: &USBD, event: Event) { - defmt::println!("USB: {} @ {}", event, dk::uptime()); + defmt::debug!("USB: {} @ {=u64:tus}", event, dk::uptime_us()); match event { Event::UsbReset => todo!(), diff --git a/nrf52-code/usb-app/src/bin/usb-2.rs b/nrf52-code/usb-app/src/bin/usb-2.rs index 84fb0923..3cbdcb4b 100644 --- a/nrf52-code/usb-app/src/bin/usb-2.rs +++ b/nrf52-code/usb-app/src/bin/usb-2.rs @@ -40,7 +40,7 @@ mod app { } fn on_event(_usbd: &USBD, event: Event) { - defmt::println!("USB: {} @ {}", event, dk::uptime()); + defmt::debug!("USB: {} @ {=u64:tus}", event, dk::uptime_us()); match event { Event::UsbReset => { @@ -67,8 +67,8 @@ mod app { // composed of a high register (WVALUEH) and a low register (WVALUEL) let wvalue: u16 = 0; - defmt::println!( - "SETUP: bmrequesttype: {}, brequest: {}, wlength: {}, windex: {}, wvalue: {}", + defmt::debug!( + "SETUP: bmrequesttype: 0b{=u8:08b}, brequest: {=u8}, wlength: {=u16}, windex: 0x{=u16:04x}, wvalue: 0x{=u16:04x}", bmrequesttype, brequest, wlength, @@ -85,7 +85,7 @@ mod app { // TODO modify `Request::parse()` in `nrf52-code/usb-lib/src/lib.rs` // so that this branch is reached - defmt::println!("GET_DESCRIPTOR Device [length={}]", length); + defmt::info!("GET_DESCRIPTOR Device [length={}]", length); defmt::println!("Goal reached; move to the next section"); dk::exit() diff --git a/nrf52-code/usb-app/src/bin/usb-3.rs b/nrf52-code/usb-app/src/bin/usb-3.rs index 5721fd15..1e6c8114 100644 --- a/nrf52-code/usb-app/src/bin/usb-3.rs +++ b/nrf52-code/usb-app/src/bin/usb-3.rs @@ -47,7 +47,7 @@ mod app { } fn on_event(usbd: &USBD, ep0in: &mut Ep0In, event: Event) { - defmt::println!("USB: {} @ {}", event, dk::uptime()); + defmt::debug!("USB: {} @ {=u64:tus}", event, dk::uptime_us()); match event { Event::UsbReset => { @@ -63,8 +63,8 @@ mod app { let windex = usbd::windex(usbd); let wvalue = usbd::wvalue(usbd); - defmt::println!( - "SETUP: bmrequesttype: {}, brequest: {}, wlength: {}, windex: {}, wvalue: {}", + defmt::debug!( + "SETUP: bmrequesttype: 0b{=u8:08b}, brequest: {=u8}, wlength: {=u16}, windex: 0x{=u16:04x}, wvalue: 0x{=u16:04x}", bmrequesttype, brequest, wlength, @@ -79,7 +79,7 @@ mod app { Request::GetDescriptor { descriptor, length } if descriptor == Descriptor::Device => { - defmt::println!("GET_DESCRIPTOR Device [length={}]", length); + defmt::info!("GET_DESCRIPTOR Device [length={}]", length); // TODO send back a valid device descriptor, truncated to `length` bytes // let desc = usb2::device::Descriptor { .. }; diff --git a/nrf52-code/usb-app/src/bin/usb-4.rs b/nrf52-code/usb-app/src/bin/usb-4.rs index 3b8d7878..1a412762 100644 --- a/nrf52-code/usb-app/src/bin/usb-4.rs +++ b/nrf52-code/usb-app/src/bin/usb-4.rs @@ -54,17 +54,17 @@ mod app { } fn on_event(usbd: &USBD, ep0in: &mut Ep0In, state: &mut State, event: Event) { - defmt::println!("USB: {} @ {}", event, dk::uptime()); + defmt::debug!("USB: {} @ {=u64:tus}", event, dk::uptime_us()); match event { // TODO change `state` as specified in chapter 9.1 USB Device States, of the USB specification Event::UsbReset => { - defmt::println!("USB reset condition detected"); + defmt::warn!("USB reset condition detected"); todo!(); } Event::UsbEp0DataDone => { - defmt::println!("EP0IN: transfer complete"); + defmt::info!("EP0IN: transfer complete"); ep0in.end(usbd); } @@ -85,8 +85,8 @@ mod app { let windex = usbd::windex(usbd); let wvalue = usbd::wvalue(usbd); - defmt::println!( - "bmrequesttype: {}, brequest: {}, wlength: {}, windex: {}, wvalue: {}", + defmt::debug!( + "SETUP: bmrequesttype: 0b{=u8:08b}, brequest: {=u8}, wlength: {=u16}, windex: 0x{=u16:04x}, wvalue: 0x{=u16:04x}", bmrequesttype, brequest, wlength, @@ -96,7 +96,7 @@ mod app { let request = Request::parse(bmrequesttype, brequest, wvalue, windex, wlength) .expect("Error parsing request"); - defmt::println!("EP0: {}", defmt::Debug2Format(&request)); + defmt::info!("EP0: {}", defmt::Debug2Format(&request)); // ^^^^^^^^^^^^^^^^^^^ this adapter is currently needed to log // `StandardRequest` with `defmt`