Devices may fail to enumerate on Windows (Part II)

[ryan-summers]

During development of a USB serial port for Stabilizer, I noted that the same code I had used on another project was not enumerating properly on Windows.

Debugging indicated that the issue was timing related, so I added tracing information to usb-device to track the internal state machine. I discovered the following trace:

INFO - Suspend
INFO - Reset
INFO - Data { ep_out: 0, ep_in_complete: 0, ep_setup: 1 }
INFO - Initial ControlPipe State: Idle
INFO - Setup Req: Request { direction: In, request_type: Standard, recipient: Device, request: 6, value: 256, index: 0, length: 64 }
INFO - Writing 8 bytes: [18, 1, 16, 2, 2, 0, 0, 8]
INFO - Final ControlPipe State: DataIn
INFO - Data { ep_out: 0, ep_in_complete: 1, ep_setup: 0 }
INFO - HandleIn ControlState: DataIn
INFO - Writing 8 bytes: [18, 1, 16, 2, 2, 0, 0, 8]
INFO - Initial ControlPipe State: DataIn
INFO - Final ControlPipe State: DataIn
INFO - Data { ep_out: 1, ep_in_complete: 1, ep_setup: 0 }
INFO - HandleIn ControlState: DataIn
INFO - Writing 2 bytes: [18, 1]
INFO - Initial ControlPipe State: DataInLast
INFO - HandleOut ControlState: DataInLast
INFO - Final ControlPipe State: Idle
INFO - Data { ep_out: 0, ep_in_complete: 1, ep_setup: 0 }
INFO - HandleIn ControlState: Idle
INFO - Initial ControlPipe State: Error
INFO - Final ControlPipe State: Error
INFO - Initial ControlPipe State: Error
INFO - Reset
INFO - Data { ep_out: 0, ep_in_complete: 0, ep_setup: 1 }
INFO - Initial ControlPipe State: Idle
INFO - Setup Req: Request { direction: In, request_type: Standard, recipient: Device, request: 6, value: 256, index: 0, length: 64 }
INFO - Writing 8 bytes: [18, 1, 16, 2, 2, 0, 0, 8]
INFO - Final ControlPipe State: DataIn
INFO - Data { ep_out: 1, ep_in_complete: 1, ep_setup: 0 }
INFO - HandleIn ControlState: DataIn
INFO - Writing 8 bytes: [18, 1, 16, 2, 2, 0, 0, 8]
INFO - Initial ControlPipe State: DataIn
INFO - HandleOut ControlState: DataIn
INFO - Final ControlPipe State: Idle
INFO - Data { ep_out: 0, ep_in_complete: 1, ep_setup: 0 }
INFO - HandleIn ControlState: Idle
INFO - Initial ControlPipe State: Error
INFO - Final ControlPipe State: Error
INFO - Data { ep_out: 0, ep_in_complete: 0, ep_setup: 1 }
INFO - Initial ControlPipe State: Error
INFO - Setup Req: Request { direction: Out, request_type: Standard, recipient: Device, request: 5, value: 53, index: 0, length: 0 }
INFO - Final ControlPipe State: StatusIn
INFO - Reset
INFO - Data { ep_out: 0, ep_in_complete: 0, ep_setup: 1 }
INFO - Initial ControlPipe State: Idle
INFO - Setup Req: Request { direction: In, request_type: Standard, recipient: Device, request: 6, value: 256, index: 0, length: 64 }
INFO - Writing 8 bytes: [18, 1, 16, 2, 2, 0, 0, 8]
INFO - Final ControlPipe State: DataIn
INFO - Data { ep_out: 1, ep_in_complete: 1, ep_setup: 0 }
INFO - HandleIn ControlState: DataIn
INFO - Writing 8 bytes: [18, 1, 16, 2, 2, 0, 0, 8]
INFO - Initial ControlPipe State: DataIn
INFO - HandleOut ControlState: DataIn
INFO - Final ControlPipe State: Idle
INFO - Data { ep_out: 0, ep_in_complete: 1, ep_setup: 0 }
INFO - HandleIn ControlState: Idle
INFO - Initial ControlPipe State: Error
INFO - Final ControlPipe State: Error
INFO - Data { ep_out: 0, ep_in_complete: 0, ep_setup: 1 }
INFO - Initial ControlPipe State: Error
INFO - Setup Req: Request { direction: Out, request_type: Standard, recipient: Device, request: 5, value: 54, index: 0, length: 0 }
INFO - Reset
INFO - Data { ep_out: 0, ep_in_complete: 0, ep_setup: 1 }
INFO - Setup Req: Request { direction: In, request_type: Standard, recipient: Device, request: 6, value: 256, index: 0, length: 64 }
INFO - Writing 8 bytes: [18, 1, 16, 2, 2, 0, 0, 8]
INFO - Final ControlPipe State: DataIn
INFO - Data { ep_out: 1, ep_in_complete: 1, ep_setup: 0 }
INFO - HandleIn ControlState: DataIn
INFO - Writing 8 bytes: [18, 1, 16, 2, 2, 0, 0, 8]
INFO - Initial ControlPipe State: DataIn
INFO - HandleOut ControlState: DataIn
INFO - Final ControlPipe State: Idle
INFO - Data { ep_out: 0, ep_in_complete: 1, ep_setup: 0 }
INFO - HandleIn ControlState: Idle
INFO - Initial ControlPipe State: Error
INFO - Final ControlPipe State: Error
INFO - Data { ep_out: 0, ep_in_complete: 0, ep_setup: 1 }
INFO - Initial ControlPipe State: Error
INFO - Setup Req: Request { direction: Out, request_type: Standard, recipient: Device, request: 5, value: 55, index: 0, length: 0 }
INFO - Final ControlPipe State: StatusIn
INFO - Suspend

The most important portion appears to be:

INFO - Data { ep_out: 0, ep_in_complete: 0, ep_setup: 1 }
INFO - Initial ControlPipe State: Idle
INFO - Setup Req: Request { direction: In, request_type: Standard, recipient: Device, request: 6, value: 256, index: 0, length: 64 }
INFO - Writing 8 bytes: [18, 1, 16, 2, 2, 0, 0, 8]
INFO - Final ControlPipe State: DataIn
INFO - Data { ep_out: 0, ep_in_complete: 1, ep_setup: 0 }
INFO - HandleIn ControlState: DataIn
INFO - Writing 8 bytes: [18, 1, 16, 2, 2, 0, 0, 8]
INFO - Initial ControlPipe State: DataIn
INFO - Final ControlPipe State: DataIn
INFO - Data { ep_out: 1, ep_in_complete: 1, ep_setup: 0 }
INFO - HandleIn ControlState: DataIn
INFO - Writing 2 bytes: [18, 1]
INFO - Initial ControlPipe State: DataInLast
INFO - HandleOut ControlState: DataInLast
INFO - Final ControlPipe State: Idle
INFO - Data { ep_out: 0, ep_in_complete: 1, ep_setup: 0 }
INFO - HandleIn ControlState: Idle
INFO - Initial ControlPipe State: Error
INFO - Final ControlPipe State: Error
INFO - Initial ControlPipe State: Error
INFO - Reset

Specifically, it looks like, as the EP0-IN is sending the last portion of data in the descriptor response, it simultaneously has received an EP0-OUT packet (zero length in this case). This causes the state machine to internall transition to Idle while the control pipe has just enqueued an EP0-IN buffer.

Then, later once the EP0-IN transfer completes, an ep_in_complete bit is set and processed. However, the internal state machine has already transitioned to Idle, so this is interpretted as a spurious IN token when it actually represents acknowledgement of the completed IN transfer.

I believe we should just update the library to ignore ep_in_complete if we're already in the IDLE state, as we may have aborted out of a previous transfer.