linux-kernelusbfirmwarecdc

How to debug CDC ACM probe failure


I am working on a USB composite device that has two CDC interfaces. I started with chip supplier's composite demo, duplicated the CDC descriptors (with different endpoint and interface numbers of course), removed the unnecessary class descriptors and added support for a second CDC instance using different endpoints.

Only one instance of the interface (the first) one can be probed by the kernel:

[186246.734619] usb 6-3.1.2.2: USB disconnect, device number 97
[186247.753706] usb 6-3.1.2.2: new high-speed USB device number 98 using xhci_hcd
[186247.885115] usb 6-3.1.2.2: New USB device found, idVendor=03eb, idProduct=2404, bcdDevice= 1.00
[186247.885119] usb 6-3.1.2.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[186247.885121] usb 6-3.1.2.2: Product: myname
[186247.885122] usb 6-3.1.2.2: Manufacturer: mystuff
[186247.885123] usb 6-3.1.2.2: SerialNumber: 123456789ABCDEF
[186247.982684] cdc_acm 6-3.1.2.2:1.0: ttyACM0: USB ACM device
[186247.983128] cdc_acm: probe of 6-3.1.2.2:1.2 failed with error -16

I traced the execution of all function calls in the firmware and they are identical for both CDC instances (interface number and endpoints are of course different). The kernel simply tries to set the CDC line coding for both instances. Even the traffic dumped with Wireshark+usbmon is identical.

The first CDC instance works without issues, I can exchange data in the terminal etc.

I found out that -16 is EBUSY. The only place I can spot it in the kernel source is in acm_suspend(). How can I debug this issue?

This is the descriptor as seen by lsusb:

Bus 006 Device 098: ID 03eb:2404 Atmel Corp. The Micro
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               2.00
  bDeviceClass          239 Miscellaneous Device
  bDeviceSubClass         2 
  bDeviceProtocol         1 Interface Association
  bMaxPacketSize0        64
  idVendor           0x03eb Atmel Corp.
  idProduct          0x2404 The Micro
  bcdDevice            1.00
  iManufacturer           1 myname
  iProduct                2 mystuff
  iSerial                 3 123456789ABCDEF
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength       0x008d
    bNumInterfaces          4
    bConfigurationValue     1
    iConfiguration          0 
    bmAttributes         0x80
      (Bus Powered)
    MaxPower              100mA
    Interface Association:
      bLength                 8
      bDescriptorType        11
      bFirstInterface         0
      bInterfaceCount         2
      bFunctionClass          2 Communications
      bFunctionSubClass       2 Abstract (modem)
      bFunctionProtocol       1 AT-commands (v.25ter)
      iFunction               0 
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         2 Communications
      bInterfaceSubClass      2 Abstract (modem)
      bInterfaceProtocol      1 AT-commands (v.25ter)
      iInterface              0 
      CDC Header:
        bcdCDC               10.01
      CDC Call Management:
        bmCapabilities       0x01
          call management
        bDataInterface          0
      CDC ACM:
        bmCapabilities       0x02
          line coding and serial state
      CDC Union:
        bMasterInterface        0
        bSlaveInterface         1 
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x83  EP 3 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval              10
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        1
      bAlternateSetting       0
      bNumEndpoints           2
      bInterfaceClass        10 CDC Data
      bInterfaceSubClass      0 
      bInterfaceProtocol      0 
      iInterface              0 
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x02  EP 2 OUT
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0200  1x 512 bytes
        bInterval               0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0200  1x 512 bytes
        bInterval               0
    Interface Association:
      bLength                 8
      bDescriptorType        11
      bFirstInterface         2
      bInterfaceCount         2
      bFunctionClass          2 Communications
      bFunctionSubClass       2 Abstract (modem)
      bFunctionProtocol       1 AT-commands (v.25ter)
      iFunction               0 
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        2
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         2 Communications
      bInterfaceSubClass      2 Abstract (modem)
      bInterfaceProtocol      1 AT-commands (v.25ter)
      iInterface              0 
      CDC Header:
        bcdCDC               10.01
      CDC Call Management:
        bmCapabilities       0x01
          call management
        bDataInterface          0
      CDC ACM:
        bmCapabilities       0x02
          line coding and serial state
      CDC Union:
        bMasterInterface        2
        bSlaveInterface         1 
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x86  EP 6 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval              10
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        3
      bAlternateSetting       0
      bNumEndpoints           2
      bInterfaceClass        10 CDC Data
      bInterfaceSubClass      0 
      bInterfaceProtocol      0 
      iInterface              0 
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x05  EP 5 OUT
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0200  1x 512 bytes
        bInterval               0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x84  EP 4 IN
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0200  1x 512 bytes
        bInterval               0
Device Qualifier (for other device speed):
  bLength                10
  bDescriptorType         6
  bcdUSB               2.00
  bDeviceClass          239 Miscellaneous Device
  bDeviceSubClass         2 
  bDeviceProtocol         1 Interface Association
  bMaxPacketSize0        64
  bNumConfigurations      1
Device Status:     0x0000
  (Bus Powered)

Solution

  • I found out that the probe problem happened due to bad CDC union descriptors. I realized that the EBUSY is not coming from acm_suspend but from within acm_probe. I was able to observe the firmware receiving set line to 9600 requests from this line on both instances https://github.com/torvalds/linux/blob/v5.15/drivers/usb/class/cdc-acm.c#L1477 but the ttyACM printk coming out only for the first instance so the issue must have been somewhere between these two lines.

    I built a custom kernel with extra printks and run it under a VM. This showed that it was usb_driver_claim_interface() that was failing. I then discovered that data_interface equals 1 during both probes which is weird because you only probe the interface once.