USB device may fail initial enumeration on Windows

[ryan-summers]

Overview

During development, I noted that my USB CDC-ACM virtual serial port was enumerating on Ubuntu without issue, but the enumeration process on Windows was failing with a note "Set Address failed".

This occurred in both debug and release configurations.

Analysis

To debug, I added RTT logging of EP0 control states, inbound requests, and written data and collected logs from the firmware on both Windows and Ubuntu.

Analysis of the logs indicates that both operating systems conduct what appears to be a partial read of the DEVICE_DESCRIPTOR as the very first communication with the device. The descriptor is 18 bytes long, but the OS appears to end the DATA stage of the control transfer early after receiving the first 8 or 16 bytes (presumably because it is only interested in determining the max packet size of EP0).

On Ubuntu, the device logs a RESET after the partial descriptor read, but this reset is not present on Windows.

After the partial descriptor read, EP0 then receives a SET_ADDRESS configuration request.

On Windows, this is where the configuration process halted. On Ubuntu, the process continues normally. My current assumption is that the usb-device goes into an error state and stalls one of the EP0 IN/OUT channels after the partial descriptor read, which causes the SET_ADDRESS to fail. On Ubuntu, a RESET occurs which removes the stall condition.

[ryan-summers]

To test my theory, I modified the state machine of control_pipe.rs to allow the data stage to end early without entering an error condition. With this modification and adjustments to process EP0-OUT before EP0-IN, the device began to enumerate on my Windows machine properly.

[ryan-summers]

RTT log from Windows (Logs not generated when PollResult = None):

[INFO] device.rs:164 - PollResult: Suspend
[INFO] device.rs:164 - PollResult: Reset
[INFO] device.rs:164 - PollResult: Data { ep_out: 0, ep_in_complete: 0, ep_setup: 1 }
[INFO] device.rs:208 - Initial ControlPipe State: Idle
[INFO] device.rs:218 - ControlPipe State: CompleteIn(Request { direction: In, request_type: Standard, recipient: Device, request: 6, value: 256, index: 0, length: 64 })
[INFO] device.rs:219 - Incoming request: Some(Request { direction: In, request_type: Standard, recipient: Device, request: 6, value: 256, index: 0, length: 64 })
[INFO] control_pipe.rs:242 - IN packet 18 bytes
[INFO] control_pipe.rs:208 - Writing 8 bytes [18, 1, 16, 2, 2, 0, 0, 8]
[INFO] device.rs:231 - Final ControlPipe State: DataIn
[INFO] device.rs:164 - PollResult: Data { ep_out: 0, ep_in_complete: 1, ep_setup: 0 }
[INFO] control_pipe.rs:208 - Writing 8 bytes [131, 4, 64, 87, 16, 0, 1, 2]
[INFO] device.rs:208 - Initial ControlPipe State: DataIn
[INFO] device.rs:218 - ControlPipe State: DataIn
[INFO] device.rs:219 - Incoming request: None
[INFO] device.rs:164 - PollResult: Data { ep_out: 1, ep_in_complete: 0, ep_setup: 0 }
[INFO] device.rs:208 - Initial ControlPipe State: DataIn
[INFO] device.rs:218 - ControlPipe State: Error
[INFO] device.rs:219 - Incoming request: None
[INFO] device.rs:231 - Final ControlPipe State: Error
[INFO] device.rs:164 - PollResult: Data { ep_out: 0, ep_in_complete: 0, ep_setup: 1 }
[INFO] device.rs:208 - Initial ControlPipe State: Error
[INFO] device.rs:218 - ControlPipe State: CompleteOut
[INFO] device.rs:219 - Incoming request: Some(Request { direction: Out, request_type: Standard, recipient: Device, request: 5, value: 28, index: 0, length: 0 })
[INFO] device.rs:231 - Final ControlPipe State: StatusIn

// Above log repeats 4x and then Windows indicates a problem enumerating the device