Hi!
I'm experiencing an issue with combination of ASMedia ASM3142
controller
(http://www.asmedia.com.tw/eng/e_show_products.php?cate_index=175&item=179)
and specific USB3 device type - industrial camera. After few seconds
from the start of image acquisition USB transfer hangs (device reports
that streaming endpoint has stalled) with the following messages
repeated several times in kernel log:
[ 137.337248] xhci_hcd 0000:02:00.0: ERROR Transfer event TRB DMA ptr not part
of current TD ep_index 2 comp_code 1
[ 137.337259] xhci_hcd 0000:02:00.0: Looking for event-dma 00000004841d9000
trb-start 00000004841dabf0 trb-end 00000004841dafe0 seg-start 00000004841da000
seg-end 00000004841daff0
.....
[ 137.346576] xhci_hcd 0000:02:00.0: ERROR Transfer event TRB DMA ptr not part
of current TD ep_index 2 comp_code 13
[ 137.346585] xhci_hcd 0000:02:00.0: Looking for event-dma 00000004841d9b60
trb-start 00000004841dabf0 trb-end 00000004841dafe0 seg-start 00000004841da000
seg-end 00000004841daff0
.....
Endpoint 2 (OUT) is used for control commands (with 0x82 IN endpoint for
ACKs) and image data is streamed through IN endpoint 0x81. The fact
that 2 bulk endpoints are used in parallel is most likely what triggers
this bug. Other devices work fine with this controller, e.g. USB3
storage, but they don't have such USB endpoints configuration. Also the
camera works fine with this controller on Windows, but only with
drivers from ASMedia, not with Microsoft's.
I've tried several Linux kernel versions including latest kernel.org
release 4.18.3.
Here is lspci -vvv -s 0000:02:00.0 output:
02:00.0 USB controller: ASMedia Technology Inc. Device 2142 (prog-if 30 [XHCI])
Subsystem: ASMedia Technology Inc. Device 2142
Physical Slot: 6
Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr-
Stepping- SERR+ FastB2B- DisINTx+
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort-
<MAbort- >SERR- <PERR- INTx-
Latency: 0, Cache Line Size: 32 bytes
Interrupt: pin A routed to IRQ 24
NUMA node: 0
Region 0: Memory at fb300000 (64-bit, non-prefetchable) [size=32K]
Capabilities: [50] MSI: Enable- Count=1/8 Maskable- 64bit+
Address: 0000000000000000 Data: 0000
Capabilities: [68] MSI-X: Enable+ Count=8 Masked-
Vector table: BAR=0 offset=00002000
PBA: BAR=0 offset=00002080
Capabilities: [78] Power Management version 3
Flags: PMEClk- DSI- D1- D2- AuxCurrent=55mA
PME(D0+,D1-,D2-,D3hot+,D3cold+)
Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME-
Capabilities: [80] Express (v2) Legacy Endpoint, MSI 00
DevCap: MaxPayload 512 bytes, PhantFunc 0, Latency L0s <64ns,
L1 <2us
ExtTag+ AttnBtn- AttnInd- PwrInd- RBE+ FLReset-
DevCtl: Report errors: Correctable- Non-Fatal- Fatal-
Unsupported-
RlxdOrd- ExtTag+ PhantFunc- AuxPwr- NoSnoop+
MaxPayload 256 bytes, MaxReadReq 512 bytes
DevSta: CorrErr+ UncorrErr- FatalErr- UnsuppReq+ AuxPwr+
TransPend-
LnkCap: Port #0, Speed 8GT/s, Width x2, ASPM L0s L1, Exit
Latency L0s <2us, L1 unlimited
ClockPM- Surprise- LLActRep- BwNot- ASPMOptComp+
LnkCtl: ASPM Disabled; RCB 64 bytes Disabled- CommClk+
ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
LnkSta: Speed 8GT/s, Width x2, TrErr- Train- SlotClk+ DLActive-
BWMgmt- ABWMgmt-
DevCap2: Completion Timeout: Not Supported, TimeoutDis-, LTR+,
OBFF Not Supported
DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-,
OBFF Disabled
LnkCtl2: Target Link Speed: 8GT/s, EnterCompliance- SpeedDis-
Transmit Margin: Normal Operating Range,
EnterModifiedCompliance- ComplianceSOS-
Compliance De-emphasis: -6dB
LnkSta2: Current De-emphasis Level: -6dB,
EqualizationComplete+, EqualizationPhase1+
EqualizationPhase2+, EqualizationPhase3+,
LinkEqualizationRequest-
Capabilities: [100 v1] Advanced Error Reporting
UESta: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt-
RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UEMsk: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt-
RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UESvrt: DLP+ SDES+ TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt-
RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
CESta: RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr-
CEMsk: RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr+
AERCap: First Error Pointer: 00, GenCap+ CGenEn- ChkCap- ChkEn-
Capabilities: [200 v1] #19
Capabilities: [300 v1] Latency Tolerance Reporting
Max snoop latency: 0ns
Max no snoop latency: 0ns
Kernel driver in use: xhci_hcd
Here is excerpt from dmesg before running test application:
[ 1.605211] xhci_hcd 0000:02:00.0: xHCI Host Controller
[ 1.605217] xhci_hcd 0000:02:00.0: new USB bus registered, assigned bus
number 5
[ 1.660014] xhci_hcd 0000:02:00.0: hcc params 0x0200ef81 hci version 0x110
quirks 0x0000000000000010
[ 1.660263] usb usb5: New USB device found, idVendor=1d6b, idProduct=0002,
bcdDevice= 4.18
[ 1.660266] usb usb5: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[ 1.660268] usb usb5: Product: xHCI Host Controller
[ 1.660269] usb usb5: Manufacturer: Linux 4.18.3-041803-generic xhci-hcd
[ 1.660271] usb usb5: SerialNumber: 0000:02:00.0
[ 1.660406] hub 5-0:1.0: USB hub found
[ 1.660414] hub 5-0:1.0: 2 ports detected
[ 1.660526] xhci_hcd 0000:02:00.0: xHCI Host Controller
[ 1.660531] xhci_hcd 0000:02:00.0: new USB bus registered, assigned bus
number 6
[ 1.660535] xhci_hcd 0000:02:00.0: Host supports USB 3.1 Enhanced SuperSpeed
[ 1.660570] usb usb6: We don't know the algorithms for LPM for this host,
disabling LPM.
[ 1.660594] usb usb6: New USB device found, idVendor=1d6b, idProduct=0003,
bcdDevice= 4.18
[ 1.660596] usb usb6: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[ 1.660598] usb usb6: Product: xHCI Host Controller
[ 1.660599] usb usb6: Manufacturer: Linux 4.18.3-041803-generic xhci-hcd
[ 1.660601] usb usb6: SerialNumber: 0000:02:00.0
[ 1.660723] hub 6-0:1.0: USB hub found
[ 1.660731] hub 6-0:1.0: 2 ports detected
[ 2.000611] usb 6-2: new SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[ 2.022542] usb 6-2: LPM exit latency is zeroed, disabling LPM.
[ 2.025524] usb 6-2: New USB device found, idVendor=20f7, idProduct=30b3,
bcdDevice= 0.00
[ 2.025527] usb 6-2: New USB device strings: Mfr=1, Product=2,
SerialNumber=10
[ 2.025529] usb 6-2: Product: xiC
[ 2.025531] usb 6-2: Manufacturer: XIMEA
[ 2.025533] usb 6-2: SerialNumber: CIMAU1633001
And from lsusb -t:
/: Bus 06.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/2p, 10000M
|__ Port 2: Dev 2, If 0, Class=Miscellaneous Device, Driver=, 5000M
|__ Port 2: Dev 2, If 1, Class=Miscellaneous Device, Driver=, 5000M
|__ Port 2: Dev 2, If 2, Class=Miscellaneous Device, Driver=, 5000M
/: Bus 05.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/2p, 480M
lsusb -v -s 6:2 output:
Bus 006 Device 002: ID 20f7:30b3 XIMEA MQ in U3V mode or MC camera
Device Descriptor:
bLength 18
bDescriptorType 1
bcdUSB 3.20
bDeviceClass 239 Miscellaneous Device
bDeviceSubClass 2 ?
bDeviceProtocol 1 Interface Association
bMaxPacketSize0 9
idVendor 0x20f7 XIMEA
idProduct 0x30b3 MQ in U3V mode or MC camera
bcdDevice 0.00
iManufacturer 1 XIMEA
iProduct 2 xiC
iSerial 10 CIMAU1633001
bNumConfigurations 1
Configuration Descriptor:
bLength 9
bDescriptorType 2
wTotalLength 116
bNumInterfaces 3
bConfigurationValue 1
iConfiguration 0
bmAttributes 0x80
(Bus Powered)
MaxPower 100mA
Interface Association:
bLength 8
bDescriptorType 11
bFirstInterface 0
bInterfaceCount 3
bFunctionClass 239 Miscellaneous Device
bFunctionSubClass 5 USB3 Vision
bFunctionProtocol 0
iFunction 3 USB3 Vision Device
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 0
bAlternateSetting 0
bNumEndpoints 2
bInterfaceClass 239 Miscellaneous Device
bInterfaceSubClass 5 USB3 Vision
bInterfaceProtocol 0
iInterface 0
** UNRECOGNIZED: 14 24 01 00 00 01 00 00 00 01 00 04 05 06 07 08 09 0a
0b 0c
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x02 EP 2 OUT
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0400 1x 1024 bytes
bInterval 0
bMaxBurst 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x82 EP 2 IN
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0400 1x 1024 bytes
bInterval 0
bMaxBurst 0
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 1
bAlternateSetting 0
bNumEndpoints 1
bInterfaceClass 239 Miscellaneous Device
bInterfaceSubClass 5 USB3 Vision
bInterfaceProtocol 2
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x81 EP 1 IN
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0400 1x 1024 bytes
bInterval 0
bMaxBurst 15
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 2
bAlternateSetting 0
bNumEndpoints 1
bInterfaceClass 239 Miscellaneous Device
bInterfaceSubClass 5 USB3 Vision
bInterfaceProtocol 1
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x83 EP 3 IN
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0400 1x 1024 bytes
bInterval 0
bMaxBurst 0
Binary Object Store Descriptor:
bLength 5
bDescriptorType 15
wTotalLength 22
bNumDeviceCaps 2
USB 2.0 Extension Device Capability:
bLength 7
bDescriptorType 16
bDevCapabilityType 2
bmAttributes 0x00000002
Link Power Management (LPM) Supported
SuperSpeed USB Device Capability:
bLength 10
bDescriptorType 16
bDevCapabilityType 3
bmAttributes 0x00
wSpeedsSupported 0x000c
Device can operate at High Speed (480Mbps)
Device can operate at SuperSpeed (5Gbps)
bFunctionalitySupport 3
Lowest fully-functional device speed is SuperSpeed (5Gbps)
bU1DevExitLat 0 micro seconds
bU2DevExitLat 0 micro seconds
Device Status: 0x0000
(Bus Powered)
Test application uses libusb, so I can provide libusb debug log and of
course any further debug information kernel can produce. Also I have
access to USB protocol analyzer. What can I do to debug this issue?
Regards,
Igor.
