On Sun, 15 Jan 2017 23:23:59 +0200, Felipe Balbi <felipe.balbi@xxxxxxxxxxxxxxx> wrote: > (it's always a good idea to Cc maintainers of drivers you're having > trouble with :) Noted, I was worried I was CC'ing you too much lately with my patches :) . > Alan Stern <stern@xxxxxxxxxxxxxxxxxxx> writes: > > The USB spec allows such things. Thanks for your confirmation. > > I don't know about DWC. The host controllers drivers I maintain work > > okay when two endpoints have the same number but different directions. > > > > What sort of host controller do you test with? Host controller is an intel xhci, managed by xhci_pci: # lspci -vvs 00:14.0 00:14.0 USB controller: Intel Corporation Sunrise Point-H USB 3.0 xHCI Controller (rev 31) (prog-if 30 [XHCI]) Subsystem: ASRock Incorporation Sunrise Point-H USB 3.0 xHCI Controller Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+ Status: Cap+ 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx- Latency: 0 Interrupt: pin A routed to IRQ 128 Region 0: Memory at df330000 (64-bit, non-prefetchable) [size=64K] Capabilities: [70] Power Management version 2 Flags: PMEClk- DSI- D1- D2- AuxCurrent=375mA PME(D0-,D1-,D2-,D3hot+,D3cold+) Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME- Capabilities: [80] MSI: Enable+ Count=1/8 Maskable- 64bit+ Address: 00000000fee00318 Data: 0000 Kernel driver in use: xhci_hcd Kernel modules: xhci_pci # lspci -ns 00:14.0 00:14.0 0c03: 8086:a12f (rev 31) Host is running: Linux x2 4.8.0-2-amd64 #1 SMP Debian 4.8.11-1 (2016-12-02) x86_64 GNU/Linux > > What does usbmon show? 8x 512bytes transfers, submitted once each, 5s timeouts, whole "host.py" trace, 3 endpoints mode: ffff9a1e04ad60c0 2806891189 S Ci:1:048:0 s 80 06 0300 0000 00ff 255 < ffff9a1e04ad60c0 2806891773 C Ci:1:048:0 0 4 = 04030904 ffff9a1e04ad60c0 2806891862 S Ci:1:048:0 s 80 06 0305 0409 00ff 255 < ffff9a1e04ad60c0 2806892148 C Ci:1:048:0 0 42 = 2a034600 75006e00 63007400 69006f00 6e004600 53005400 65007300 74004400 ffff9a1e04ad60c0 2806892318 S Ci:1:048:0 s 80 06 0300 0000 00ff 255 < ffff9a1e04ad60c0 2806892566 C Ci:1:048:0 0 4 = 04030904 ffff9a1e04ad60c0 2806892578 S Ci:1:048:0 s 80 06 0305 0409 00ff 255 < ffff9a1e04ad60c0 2806892831 C Ci:1:048:0 0 42 = 2a034600 75006e00 63007400 69006f00 6e004600 53005400 65007300 74004400 ffff9a1e04ad60c0 2806893000 S Ci:1:048:0 s c1 02 0000 0000 0001 1 < ffff9a1e04ad60c0 2806893778 C Ci:1:048:0 -32 0 ffff9a1e04ad60c0 2806893870 S Co:1:048:0 s 41 02 0000 0000 0001 1 = 61 ffff9a1e04ad60c0 2806894751 C Co:1:048:0 -32 0 ffff9a1e04ad60c0 2806894843 S Ci:1:048:0 s c1 01 0000 0000 0001 1 < ffff9a1e04ad60c0 2806896079 C Ci:1:048:0 0 1 = 4e ffff9a1e04ad60c0 2806896284 S Ci:1:048:0 s c1 01 0000 0000 0002 2 < ffff9a1e04ad60c0 2806896949 C Ci:1:048:0 0 2 = 4e4f ffff9a1e04ad60c0 2806897094 S Ci:1:048:0 s c1 01 0000 0000 0003 3 < ffff9a1e04ad60c0 2806897810 C Ci:1:048:0 0 3 = 4e4f54 ffff9a1e04ad60c0 2806897927 S Ci:1:048:0 s c1 01 0000 0000 0004 4 < ffff9a1e04ad60c0 2806898484 C Ci:1:048:0 0 4 = 4e4f5420 ffff9a1e04ad60c0 2806898631 S Ci:1:048:0 s c1 01 0000 0000 0005 5 < ffff9a1e04ad60c0 2806899619 C Ci:1:048:0 0 5 = 4e4f5420 53 ffff9a1e04ad60c0 2806899726 S Ci:1:048:0 s c1 01 0000 0000 0006 6 < ffff9a1e04ad60c0 2806900391 C Ci:1:048:0 0 6 = 4e4f5420 5345 ffff9a1e04ad60c0 2806900559 S Ci:1:048:0 s c1 01 0000 0000 0007 7 < ffff9a1e04ad60c0 2806901094 C Ci:1:048:0 0 7 = 4e4f5420 534554 ffff9a1e04ad60c0 2806901260 S Ci:1:048:0 s c1 01 0000 0000 0008 8 < ffff9a1e04ad60c0 2806901690 C Ci:1:048:0 0 7 = 4e4f5420 534554 ffff9a1e04ad60c0 2806901787 S Co:1:048:0 s 41 01 0000 0000 000b 11 = 666f6f20 62617220 62617a ffff9a1e04ad60c0 2806902191 C Co:1:048:0 0 11 > ffff9a1e04ad60c0 2806902352 S Ci:1:048:0 s c1 01 0000 0000 0040 64 < ffff9a1e04ad60c0 2806902775 C Ci:1:048:0 0 11 = 666f6f20 62617220 62617a ffff9a1e04ad60c0 2806902940 S Bo:1:048:1 -115 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffff9a1e04ad60c0 2806902963 C Bo:1:048:1 0 512 > ffff9a1e04ad63c0 2806902970 S Bo:1:048:1 -115 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffff9a1bf65103c0 2806902986 S Bo:1:048:1 -115 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffff9a1e04ad63c0 2806903013 C Bo:1:048:1 0 512 > ffff9a1bf65106c0 2806903015 S Bo:1:048:1 -115 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffff9a1bf65103c0 2806903018 C Bo:1:048:1 0 512 > ffff9a1bf6510240 2806903028 S Bo:1:048:1 -115 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffff9a1bf6510a80 2806903039 S Bo:1:048:1 -115 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffff9a1bf65106c0 2806903044 C Bo:1:048:1 0 512 > ffff9a1bf6510240 2806903060 C Bo:1:048:1 0 512 > ffff9a1bf6510a80 2806903062 C Bo:1:048:1 0 512 > ffff9a1bf65100c0 2806903064 S Bo:1:048:1 -115 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffff9a1bf65100c0 2806903083 C Bo:1:048:1 0 512 > ffff9a1bf6510e40 2806903087 S Bo:1:048:1 -115 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffff9a1bf6510e40 2806903126 C Bo:1:048:1 0 512 > ffff9a1bf6510e40 2806903318 S Bi:1:048:1 -115 512 < ffff9a1bf65100c0 2806903352 S Bi:1:048:1 -115 512 < ffff9a1bf6510a80 2806903367 S Bi:1:048:1 -115 512 < ffff9a1bf6510240 2806903383 S Bi:1:048:1 -115 512 < ffff9a1bf65106c0 2806903422 S Bi:1:048:1 -115 512 < ffff9a1bf65103c0 2806903435 S Bi:1:048:1 -115 512 < ffff9a1e04ad63c0 2806903446 S Bi:1:048:1 -115 512 < ffff9a1e04ad60c0 2806903457 S Bi:1:048:1 -115 512 < ffff9a1bf6510e40 2811903443 C Bi:1:048:1 -2 0 ffff9a1bf65100c0 2811903530 C Bi:1:048:1 -2 0 ffff9a1bf6510a80 2811903605 C Bi:1:048:1 -2 0 ffff9a1bf6510240 2811903701 C Bi:1:048:1 -2 0 ffff9a1bf65106c0 2811903742 C Bi:1:048:1 -2 0 ffff9a1bf65103c0 2811903782 C Bi:1:048:1 -2 0 ffff9a1e04ad63c0 2811903821 C Bi:1:048:1 -2 0 ffff9a1e04ad60c0 2811903861 C Bi:1:048:1 -2 0 ffff9a1e04ad60c0 2811904324 S Bi:1:048:2 -115 512 < ffff9a1e04ad60c0 2811904361 C Bi:1:048:2 0 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffff9a1e04ad63c0 2811904404 S Bi:1:048:2 -115 512 < ffff9a1e04ad63c0 2811904428 C Bi:1:048:2 0 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffff9a1bf65103c0 2811904469 S Bi:1:048:2 -115 512 < ffff9a1bf65103c0 2811904492 C Bi:1:048:2 0 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffff9a1bf65106c0 2811904527 S Bi:1:048:2 -115 512 < ffff9a1bf65106c0 2811904550 C Bi:1:048:2 0 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffff9a1bf6510240 2811904581 S Bi:1:048:2 -115 512 < ffff9a1bf6510240 2811904610 C Bi:1:048:2 0 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffff9a1bf6510a80 2811904635 S Bi:1:048:2 -115 512 < ffff9a1bf6510a80 2811904658 C Bi:1:048:2 0 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffff9a1bf65100c0 2811904688 S Bi:1:048:2 -115 512 < ffff9a1bf65100c0 2811904709 C Bi:1:048:2 0 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ffff9a1bf6510e40 2811904739 S Bi:1:048:2 -115 512 < ffff9a1bf6510e40 2811904759 C Bi:1:048:2 0 512 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 With my USB protocol analyser, I could confirm I see IN transactions for EP1, which are NAK'ed all the way. > also, which kernel are you running on dwc3 side? Which platform is it? It is on an intel edison. Kernel is 4.10-rc3 + your testing/fixes branch + edison patches from https://github.com/andy-shev/linux/tree/eds I pushed my latest build's source here: https://github.com/vpelletier/linux/tree/eds_4.10-rc3 > In order to have any idea of what's going on, I need tracepoints from > dwc3. [...] > compress and send me traces Attached. After enabling trace I thought I should cause functionfs to re-initialise the device, so the trace contains the result of # echo > /sys/kernel/config/usb_gadget/g1/UDC (restarting device.py) # echo dwc3.1.auto > /sys/kernel/config/usb_gadget/g1/UDC BTW, re-initialising the device does not always work, and when it works it often causes a timeout. Here is what host syslog has about attached trace: Jan 15 23:20:26 localhost kernel: [253820.464321] usb 1-10: USB disconnect, device number 48 Jan 15 23:20:43 localhost kernel: [253837.344261] usb 1-10: new high-speed USB device number 49 using xhci_hcd Jan 15 23:20:49 localhost kernel: [253842.652321] usb 1-10: unable to read config index 0 descriptor/start: -110 Jan 15 23:20:49 localhost kernel: [253842.652326] usb 1-10: can't read configurations, error -110 Jan 15 23:20:49 localhost kernel: [253842.772268] usb 1-10: new high-speed USB device number 50 using xhci_hcd Jan 15 23:20:49 localhost kernel: [253842.918985] usb 1-10: New USB device found, idVendor=1d6b, idProduct=0104 Jan 15 23:20:49 localhost kernel: [253842.918989] usb 1-10: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Jan 15 23:20:49 localhost kernel: [253842.918993] usb 1-10: Product: tesla Jan 15 23:20:49 localhost kernel: [253842.918995] usb 1-10: Manufacturer: vpelletier Jan 15 23:20:49 localhost kernel: [253842.918998] usb 1-10: SerialNumber: FZED443D01T42501 Jan 15 23:20:49 localhost mtp-probe: checking bus 1, device 50: "/sys/devices/pci0000:00/0000:00:14.0/usb1/1-10" Jan 15 23:20:49 localhost mtp-probe: bus: 1, device: 50 was not an MTP device Sometimes, ep0 just gets stuck during SET_CONFIGURATION, but then does work for test's part which involves it. EP1 & above do not work. > > What happens when you run your test with dummy-hcd? > > this is a good idea too. Tested (on the edison, as it was the most convenient place to build that module and debian kernel on host does not have it), the whole test suite passes there. This said, dummy_hcd allocates endpoints on very different addresses: 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 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x86 EP 6 IN bmAttributes 2 Transfer Type Bulk Synch Type None Usage Type Data wMaxPacketSize 0x0200 1x 512 bytes bInterval 0 Back the dwc3 I tried pushing the IN descriptor first (IN, OUT, IN instead of OUT, IN, IN). ep1in is still silent, so it looks like in the event of IN+OUT endpoint address (4 LSb), OUT wins and IN looses whatever the initialisation order. > We don't even know which kernel he's running on dwc3 side :-) It could > also be a bug on his python functionfs lib. It could very well be, yes. I forgot to mention that python-functionfs is very new, and has only ever been tested by ma, on this edison dwc3 on device side (I'm trying to get my hands on a Raspberry pi zero, but could not find one yet - I'm hesitating to pick an A+ with a micro-USB-to-USB-A adapter instead). On host side, I tested on 2 different intel xHCI hosts (a ~2years old thinkpad and my main machine, whose lspci I pasted above). > Vincent, can you compile my xhci-cleanup branch from my usb.org tree > (see MAINTAINERS file for the URL. Hint, it's on git.kernel.org) and run > it on your xHCI side and *also* capture tracepoints from xHCI? Given that the USB analyser does see traffic on the bus and it's the device which NAKs, I think I can skip this - unless you think there is more to see there. Regards, -- Vincent Pelletier
Attachment:
dwc3-trace.txt.gz
Description: application/gzip