CODEWITHSUNDEEP
windowsusbwinusblibusb-win32
Konamiman
Konamiman

Reputation: 50273

USB device prototype timeouts with WinUSB or HID drivers, works fine with libusb

I'm trying to create a prototype for an USB (1.1) HID device using an Arudino board and a CH376 module. I have managed to write the Arduino code that sets the CH376 in device mode and handles all the USB transactions.

As long as I declare the device as belonging to the "vendor specific" class, Windows 10 recognizes the device as an "Unknown device" and properly shows its VID and PID when I ask for the device details in control panel (device properties - details - hardware ids). So far so good. Then I can use Zadig to assign a libusb driver to the device, which will then show under the "libusb devices" category in control panel; still all good, and I'm able to communicate with the device using the libusb functions.

Now here comes the problem. If I try to use WinUSB instead of libusb to manage the device, the following happens when I plug or reset the device:

  1. Windows does the usual device initialization sequence: it requests the device descriptor (64 bytes), then assigns an address to the device, then requests the device descriptor again (only 18 bytes this time), then requests the configuration descriptor.

  2. After five seconds Windows requests the device descriptor again. That's where the device appears in the device manager, with a "This device is working properly" status.

  3. After five more seconds Windows requests the configuration descriptor again, but after retrieving just the first 8 bytes (that's the size of the control endpoint), it disconnects the device and shows it with an exclamation mark in device manager.

If I go to device properties, "general" tab, it says:

This device cannot start. (Code 10)

{Device Timeout}
The specified I/O operation on %hs was not completed before the time-out period expired.

And if I go to the "events" tab, the last one is "Device not started (WinUSB)" with these details:

Device USB\VID_1209&PID_0002\8&339ad878&0&2 had a problem starting.

Driver Name: oem168.inf
Class Guid: {88bae032-5a81-49f0-bc3d-a4ff138216d6}
Service: WinUSB
Lower Filters: 
Upper Filters: 
Problem: 0xA
Problem Status: 0xC00000B5

Now, if instead of declaring the device as belonging to the "vendor specific" class I declare it as a HID device and let Windows choose the proper driver, the behavior is the same, but the error message in the "general" tab is:

This device cannot start. (Code 10)

The I/O request was canceled.

...and the last event:

Device USB\VID_1209&PID_0002\8&339ad878&0&2 had a problem starting.

Driver Name: input.inf
Class Guid: {745a17a0-74d3-11d0-b6fe-00a0c90f57da}
Service: HidUsb
Lower Filters: 
Upper Filters: 
Problem: 0xA
Problem Status: 0xC0000120

I suspect that the prototype is maybe too slow for the Windows built-in USB device management libraries and libusb is more permissive, but I find this weird (the code in the Arduino board is just checking for events from the CH376 and handling them immediately in a loop) and I'm wondering if I might be doing something wrong.

Here's a dump of the trace generated by the Arduino code. The SETUP/IN/OUT events mean that the token processing has already finished; for IN tokens, any data I've written before ("Writing X bytes" logs) has been sent. By using libusb I can confirm that the data logged is indeed what I'm sending.

Int: USB_SUSPEND
Int: WAKE_UP
Int: WAKE_UP
Int: EP0_SETUP
  0x80 0x06 0x00 0x01 0x00 0x00 0x40 0x00 
  GET_DESCRIPTOR: DEVICE
  Writing 8 bytes: 0x12 0x01 0x10 0x01 0x00 0x00 0x00 0x08 
Int: EP0_IN
  Writing 8 bytes: 0x09 0x12 0x02 0x00 0x00 0x01 0x01 0x02 
Int: EP0_OUT
Int: EP0_OUT
Int: EP0_OUT
Int: EP0_OUT
Int: EP0_OUT
Int: EP0_SETUP
  0x00 0x05 0x18 0x00 0x00 0x00 0x00 0x00 
  SET_ADDRESS: 24
Int: EP0_IN
  Setting address: 24
Int: EP0_SETUP
  0x80 0x06 0x00 0x01 0x00 0x00 0x12 0x00 
  GET_DESCRIPTOR: DEVICE
  Writing 8 bytes: 0x12 0x01 0x10 0x01 0x00 0x00 0x00 0x08 
Int: EP0_IN
  Writing 8 bytes: 0x09 0x12 0x02 0x00 0x00 0x01 0x01 0x02 
Int: EP0_IN
  Writing 2 bytes: 0x00 0x01 
Int: EP0_IN
Int: EP0_OUT
Int: EP0_SETUP
  0x80 0x06 0x00 0x02 0x00 0x00 0xFF 0x00 
  GET_DESCRIPTOR: CONFIGURATION
  Writing 8 bytes: 0x09 0x02 0x22 0x00 0x01 0x01 0x00 0x80 
Int: EP0_IN
  Writing 8 bytes: 0x32 0x09 0x04 0x00 0x00 0x01 0x03 0x00 
Int: EP0_IN
  Writing 8 bytes: 0x00 0x00 0x09 0x21 0x10 0x01 0x00 0x01 
Int: EP0_IN
  Writing 8 bytes: 0x22 0x29 0x00 0x07 0x05 0x81 0x03 0x03 
Int: EP0_IN
  Writing 2 bytes: 0x00 0x0A 
Int: EP0_IN
Int: EP0_OUT

(5 seconds pause, no entry in device manager yet)

Int: EP0_SETUP
  0x80 0x06 0x00 0x01 0x00 0x00 0x12 0x00 
  GET_DESCRIPTOR: DEVICE
  Writing 8 bytes: 0x12 0x01 0x10 0x01 0x00 0x00 0x00 0x08 
Int: EP0_IN
  Writing 8 bytes: 0x09 0x12 0x02 0x00 0x00 0x01 0x01 0x02 
Int: EP0_IN
  Writing 2 bytes: 0x00 0x01 
Int: EP0_IN
Int: EP0_OUT

(5 seconds pause again, the device shows in device manager as working properly)

Int: EP0_SETUP
  0x80 0x06 0x00 0x02 0x00 0x00 0x09 0x00 
  GET_DESCRIPTOR: CONFIGURATION
  Writing 8 bytes: 0x09 0x02 0x22 0x00 0x01 0x01 0x00 0x80 
Int: USB_SUSPEND

(The device shows with exclamation mark now)

By the way I get these traces by writing to the serial port, which is then read by the computer. Thinking that this might be slowing down the entire processing I tried disabling any serial port communication, and the result was the same.

So my questions are:

  1. Am I doing something wrong? Or is Windows at fault?
  2. If the later, does Windows 10 provide any way to increase the timeout for the WinUSB/HID devices processing (if that's really the issue)?

EDIT

If I use Microsoft's USB hardware verifier I get the following output:

Event Message: USBXHCI Device Update
VendorID/ProductID: 0x1209/0x2
PortPath:  0x4, 0x4, 0x4, 0x1, 0x0, 0x0
HWVerify Errors Encountered so far:
    #1: (UsbHub3/171): Request for Language ID String Descriptor Failed
    #2: (UsbHub3/132): Device Control Transfer Error

...which is quite weird because the device doesn't seem to be receiving any request for a string descriptor at all!

EDIT 2

Per suggestion in comments I used Wireshark with USBPcap and What I see is:

This is consistent with the last two requests I see with my own tracing.

EDIT 3

In order to not make the question text growing too much I have created a gist containing:

And here's the schematic of the CH376 module I'm using (that's all the technical info I have found about the module):

enter image description here

EDIT 4

As suggested in comments I have modified my code so that the device now reports itself as a USB 2.0 device and provides a serial number string. Now the sequence of events from the perspective of the device is:

Interestingly, the Wireshark trace is exactly the same one: the languages request and the Microsoft-specific descriptor request don't show up!

The pattern seems to be that requests that are followed by the 5 second pause are invisible to Wireshark so maybe they aren't properly processed by my code and aren't considered completed by the host, but I can't see why (as I'm doing the same processing as in the second get device descriptor request, which succeeds).

Also worth noting that now I'm getting not one but six OUT token interrupts when the first device descriptor request finishes. May this be a symptom of a timing issue?

EDIT 5

Definitely looking like a timing issue.

I've used Zadig to set the driver for the device as libusb, then I tried to send a handful of descriptor requests in a loop; the result is that one in two requests fails, consistently. BUT if I place a 1ms delay between requests, then all of them work fine! It's as if the chip needs a "cooldown period" after a successful request. The failed requests don't appear on Wireshark or on my own logs, so it seems that the SETUP token itself is lost.

Is there any way to instruct Windows to wait a little bit between requests for a given device?

Upvotes: 2

Views: 1879

Answers (2)

S0urceror
S0urceror

Reputation: 51

I've been investigating this further and found more Chinese examples on Github. What struck me was that there they add a variable amount of UNLOCK_USB commands at EP0_IN.

Once I did that I had more luck with getting a Serial device registered. Otherwise it was sitting in a loop with retries every 5secs.

So at USB_INT_EP0_IN add an extra CMD_UNLOCK_USB after processing whatever needed processing. See more here.

Upvotes: 1

S0urceror
S0urceror

Reputation: 51

I checked your code and found out that:

#define USB_REQ_SET_CONFIGURATION is 9 not 8

On a Teensy2 driving the CH376s via SPI it showed up correctly on my Mac like this:

         NestorDevice:

              Product ID: 0x0002
              Vendor ID: 0x1209
              Version: 1.00
              Speed: Up to 12 Mb/s
              Location ID: 0x14223000 / 48
              Current Available (mA): 500
              Current Required (mA): 100
              Extra Operating Current (mA): 0

I haven't tried communicating with it yet.

Also know that timing is everything. When I run your code on the Mac, relaying all the commands via serial to the Teensy, I miss certain events. The Mac is very rapidly firing off all the commands and the delay via serial is too much.

EDIT

There are two types of reads:

CMD01_RD_USB_DATA0  EQU         027H             ; / * Read the data block from the current USB interrupt endpoint buffer or the host endpoint receive buffer * /
; / * Output: length, data stream * /

CMD01_RD_USB_DATA   EQU         028H             ; / * Device mode: Read the data block from the current USB interrupt endpoint buffer and release the buffer, equivalent to CMD01_RD_USB_DATA0 + CMD00_UNLOCK_USB * /
; / * Output: length, data stream * /

What if we use the latter function? Would it release the buffer earlier and be ready for the next event? I'll give it a try over here to see if it makes sense.

Upvotes: 4

Related Questions