Hi Felipe, I'm running g_webcam with uvc-gadget [1] on the DUT on v4.10 with commit 4fbac5206afd reverted. The first time I plug the DUT to host and run luvcview I can see the video test pattern so all OK. If I close luvcview and restart it without disconnecting the DUT then I don't see the test pattern on luvcview and dwc3 trace shows Bus Expiry. It seems that we don't try to recover an ISO bus expiry in __dwc3_gadget_start_isoc()? Is Bus Expiry non recoverable? As per the manual it says that if we hit bus expiry we should send ENDTRANSFER command and wait for another XFERNOTREADY event and send the STARTTRANSFER again with new future microframe time. I'm pasting portions of good case vs bad case below. Full trace is available at [2]. FYI this behaviour is the same in v4.4 as well. I haven't tried older kernels. Any hints to resolve this appreciated. Thanks. -- cheers, -roger [1] - git://git.ideasonboard.org/uvc-gadget.git [2] - http://pastebin.ubuntu.com/24090440/ # tracer: nop # # entries-in-buffer/entries-written: 12814/12814 #P:2 # # _-----=> irqs-off # / _----=> need-resched # | / _---=> hardirq/softirq # || / _--=> preempt-depth # ||| / delay # TASK-PID CPU# |||| TIMESTAMP FUNCTION # | | | |||| | | ################################# #Good case: Line 545 in pastebin [2] ################################# irq/456-dwc3-2104 [001] d... 76.824531: dwc3_gadget_ep_cmd: ep2in: cmd 'Set Endpoint Configuration' [1025] params 00042002 0a000600 00000000 --> status: Successful irq/456-dwc3-2104 [001] d... 76.824543: dwc3_gadget_ep_enable: ep2in: mps 1024/1024 streams 15 burst 0 ring 0/0 flags E:swbpm:e:< irq/456-dwc3-2104 [001] d... 76.824565: dwc3_event: event (000020c2): ep0in: Transfer Not Ready (Not Active) [Status Phase] uvc-gadget-2107 [001] .... 76.832136: dwc3_alloc_request: ep2in: req ec807c00 length 0/0 zsI ==> 0 uvc-gadget-2107 [001] .... 76.832144: dwc3_alloc_request: ep2in: req ec964900 length 0/0 zsI ==> 0 uvc-gadget-2107 [001] .... 76.832176: dwc3_alloc_request: ep2in: req ed6c9800 length 0/0 zsI ==> 0 uvc-gadget-2107 [001] .... 76.832180: dwc3_alloc_request: ep2in: req ed6c9600 length 0/0 zsI ==> 0 uvc-gadget-2107 [001] d... 76.832234: dwc3_ep_queue: ep2in: req ec807c00 length 0/1024 zsI ==> -115 uvc-gadget-2107 [001] d... 76.832246: dwc3_ep_queue: ep2in: req ec964900 length 0/1024 zsI ==> -115 uvc-gadget-2107 [001] d... 76.832254: dwc3_ep_queue: ep2in: req ed6c9800 length 0/1024 zsI ==> -115 uvc-gadget-2107 [001] d... 76.832261: dwc3_ep_queue: ep2in: req ed6c9600 length 0/1024 zsI ==> -115 uvc-gadget-2107 [001] dn.. 76.832760: dwc3_prepare_trb: ep0in: 0/0 trb f224f000 buf 00000000fd858000 size 0 ctrl 00000c33 (HLcs:SC:status2) uvc-gadget-2107 [001] dn.. 76.832770: dwc3_gadget_ep_cmd: ep0in: cmd 'Start Transfer' [1030] params 00000000 fd859000 00000000 --> status: Successful irq/456-dwc3-2104 [001] d... 76.832882: dwc3_event: event (0000c042): ep0in: Transfer Complete [Status Phase] irq/456-dwc3-2104 [001] d... 76.832886: dwc3_complete_trb: ep0out: 0/2 trb f224f000 buf 00000000fd858000 size 0 ctrl 00000c32 (hLcs:SC:status2) irq/456-dwc3-2104 [001] d... 76.832891: dwc3_gadget_giveback: ep0out: req ed516700 length 0/0 zsI ==> 0 irq/456-dwc3-2104 [001] d... 76.832899: dwc3_prepare_trb: ep0out: 0/2 trb f224f000 buf 00000000fd858000 size 8 ctrl 00000c23 (HLcs:SC:setup) irq/456-dwc3-2104 [001] d... 76.832907: dwc3_gadget_ep_cmd: ep0out: cmd 'Start Transfer' [1030] params 00000000 fd859000 00000000 --> status: Successful uvc-gadget-2107 [001] d... 76.833015: dwc3_gadget_ep_cmd: ep0out: cmd 'Set Stall' [1028] params 00000000 00000000 00000000 --> status: Successful uvc-gadget-2107 [001] d... 76.833020: dwc3_prepare_trb: ep0out: 0/2 trb f224f000 buf 00000000fd858000 size 8 ctrl 00000c23 (HLcs:SC:setup) uvc-gadget-2107 [001] d... 76.833026: dwc3_gadget_ep_cmd: ep0out: cmd 'Start Transfer' [1030] params 00000000 fd859000 00000000 --> status: No Resource irq/456-dwc3-2104 [001] d... 77.101929: dwc3_event: event (0000c040): ep0out: Transfer Complete [Setup Phase] irq/456-dwc3-2104 [001] d... 77.101933: dwc3_ctrl_req: bRequestType 80 bRequest 06 wValue 0306 wIndex 0409 wLength 255 irq/456-dwc3-2104 [001] d... 77.101943: dwc3_prepare_trb: ep0in: 0/0 trb f224f000 buf 00000000ac88c800 size 32 ctrl 00000c53 (HLcs:SC:data) irq/456-dwc3-2104 [001] d... 77.101951: dwc3_gadget_ep_cmd: ep0in: cmd 'Start Transfer' [1030] params 00000000 fd859000 00000000 --> status: Successful irq/456-dwc3-2104 [001] d... 77.101956: dwc3_event: event (000010c2): ep0in: Transfer Not Ready (Not Active) [Data Phase] irq/456-dwc3-2104 [001] d... 77.102041: dwc3_event: event (0000c042): ep0in: Transfer Complete [Data Phase] irq/456-dwc3-2104 [001] d... 77.102045: dwc3_complete_trb: ep0out: 0/2 trb f224f000 buf 00000000ac88c800 size 0 ctrl 00000c52 (hLcs:SC:data) irq/456-dwc3-2104 [001] d... 77.102051: dwc3_gadget_giveback: ep0out: req ed516700 length 32/32 ZsI ==> 0 irq/456-dwc3-2104 [001] d... 77.102055: dwc3_event: event (000020c0): ep0out: Transfer Not Ready (Not Active) [Status Phase] irq/456-dwc3-2104 [001] d... 77.102057: dwc3_prepare_trb: ep0out: 0/2 trb f224f000 buf 00000000fd858000 size 0 ctrl 00000c43 (HLcs:SC:status3) irq/456-dwc3-2104 [001] d... 77.102064: dwc3_gadget_ep_cmd: ep0out: cmd 'Start Transfer' [1030] params 00000000 fd859000 00000000 --> status: Successful irq/456-dwc3-2104 [001] d... 77.102101: dwc3_event: event (0000c040): ep0out: Transfer Complete [Status Phase] irq/456-dwc3-2104 [001] d... 77.102103: dwc3_complete_trb: ep0out: 0/2 trb f224f000 buf 00000000fd858000 size 0 ctrl 00000c42 (hLcs:SC:status3) irq/456-dwc3-2104 [001] d... 77.102108: dwc3_prepare_trb: ep0out: 0/2 trb f224f000 buf 00000000fd858000 size 8 ctrl 00000c23 (HLcs:SC:setup) irq/456-dwc3-2104 [001] d... 77.102115: dwc3_gadget_ep_cmd: ep0out: cmd 'Start Transfer' [1030] params 00000000 fd859000 00000000 --> status: Successful irq/456-dwc3-2104 [001] d... 77.105063: dwc3_event: event (a74f10ca): ep2in: Transfer Not Ready (Not Active) irq/456-dwc3-2104 [001] d... 77.105070: dwc3_prepare_trb: ep2in: 1/4 trb f22a2000 buf 00000000ac9ac000 size 1024 ctrl 00000c61 (Hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.105075: dwc3_prepare_trb: ep2in: 2/4 trb f22a2010 buf 00000000ad44a800 size 1024 ctrl 00000c61 (Hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.105079: dwc3_prepare_trb: ep2in: 3/4 trb f22a2020 buf 00000000ad1ef000 size 1024 ctrl 00000c61 (Hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.105083: dwc3_prepare_trb: ep2in: 4/4 trb f22a2030 buf 00000000ad27b800 size 1024 ctrl 00000c61 (Hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.105091: dwc3_gadget_ep_cmd: ep2in: cmd 'Start Transfer' [-1487731706] params 00000000 fd86b000 00000000 --> status: Successful irq/456-dwc3-2104 [001] d... 77.105575: dwc3_event: event (a753408a): ep2in: Transfer In-Progress irq/456-dwc3-2104 [001] d... 77.105578: dwc3_complete_trb: ep2in: 3/4 trb f22a2000 buf 00000000ac9ac000 size 0 ctrl 29d4cc60 (hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.105584: dwc3_gadget_giveback: ep2in: req ec807c00 length 1024/1024 zsI ==> 0 irq/456-dwc3-2104 [001] d... 77.105608: dwc3_ep_queue: ep2in: req ec807c00 length 0/1024 zsI ==> -115 irq/456-dwc3-2104 [001] d... 77.105700: dwc3_event: event (a754408a): ep2in: Transfer In-Progress irq/456-dwc3-2104 [001] d... 77.105702: dwc3_complete_trb: ep2in: 2/4 trb f22a2010 buf 00000000ad44a800 size 0 ctrl 29d50c60 (hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.105707: dwc3_gadget_giveback: ep2in: req ec964900 length 1024/1024 zsI ==> 0 irq/456-dwc3-2104 [001] d... 77.105713: dwc3_ep_queue: ep2in: req ec964900 length 0/1024 zsI ==> -115 irq/456-dwc3-2104 [001] d... 77.105824: dwc3_event: event (a755408a): ep2in: Transfer In-Progress irq/456-dwc3-2104 [001] d... 77.105826: dwc3_complete_trb: ep2in: 1/4 trb f22a2020 buf 00000000ad1ef000 size 0 ctrl 29d54c60 (hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.105831: dwc3_gadget_giveback: ep2in: req ed6c9800 length 1024/1024 zsI ==> 0 irq/456-dwc3-2104 [001] d... 77.105837: dwc3_ep_queue: ep2in: req ed6c9800 length 0/1024 zsI ==> -115 irq/456-dwc3-2104 [001] d... 77.105949: dwc3_event: event (a756408a): ep2in: Transfer In-Progress irq/456-dwc3-2104 [001] d... 77.105953: dwc3_complete_trb: ep2in: 0/4 trb f22a2030 buf 00000000ad27b800 size 0 ctrl 29d58c60 (hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.105958: dwc3_gadget_giveback: ep2in: req ed6c9600 length 1024/1024 zsI ==> 0 irq/456-dwc3-2104 [001] d... 77.105964: dwc3_ep_queue: ep2in: req ed6c9600 length 0/1024 zsI ==> -115 irq/456-dwc3-2104 [001] d... 77.105972: dwc3_gadget_ep_cmd: ep2in: cmd 'End Transfer' [331016] params 00000000 00000000 00000000 --> status: Successful irq/456-dwc3-2104 [001] d... 77.106120: dwc3_event: event (080501ca): ep2in: Endpoint Command Complete irq/456-dwc3-2104 [001] d... 77.106198: dwc3_event: event (a75710ca): ep2in: Transfer Not Ready (Not Active) irq/456-dwc3-2104 [001] d... 77.106201: dwc3_prepare_trb: ep2in: 1/4 trb f22a2040 buf 00000000ac9ac000 size 1024 ctrl 00000c61 (Hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.106205: dwc3_prepare_trb: ep2in: 2/4 trb f22a2050 buf 00000000ad44a800 size 1024 ctrl 00000c61 (Hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.106209: dwc3_prepare_trb: ep2in: 3/4 trb f22a2060 buf 00000000ad1ef000 size 1024 ctrl 00000c61 (Hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.106215: dwc3_prepare_trb: ep2in: 4/4 trb f22a2070 buf 00000000ad27b800 size 1024 ctrl 00000c61 (Hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.106222: dwc3_gadget_ep_cmd: ep2in: cmd 'Start Transfer' [-1487207418] params 00000000 fd86b040 00000000 --> status: Successful irq/456-dwc3-2104 [001] d... 77.106575: dwc3_event: event (a75b408a): ep2in: Transfer In-Progress irq/456-dwc3-2104 [001] d... 77.106577: dwc3_complete_trb: ep2in: 3/4 trb f22a2040 buf 00000000ac9ac000 size 0 ctrl 29d6cc60 (hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.106582: dwc3_gadget_giveback: ep2in: req ec807c00 length 1024/1024 zsI ==> 0 irq/456-dwc3-2104 [001] d... 77.106588: dwc3_ep_queue: ep2in: req ec807c00 length 0/1024 zsI ==> -115 irq/456-dwc3-2104 [001] d... 77.106699: dwc3_event: event (a75c408a): ep2in: Transfer In-Progress irq/456-dwc3-2104 [001] d... 77.106701: dwc3_complete_trb: ep2in: 2/4 trb f22a2050 buf 00000000ad44a800 size 0 ctrl 29d70c60 (hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.106706: dwc3_gadget_giveback: ep2in: req ec964900 length 1024/1024 zsI ==> 0 irq/456-dwc3-2104 [001] d... 77.106712: dwc3_ep_queue: ep2in: req ec964900 length 0/1024 zsI ==> -115 irq/456-dwc3-2104 [001] d... 77.106824: dwc3_event: event (a75d408a): ep2in: Transfer In-Progress irq/456-dwc3-2104 [001] d... 77.106826: dwc3_complete_trb: ep2in: 1/4 trb f22a2060 buf 00000000ad1ef000 size 0 ctrl 29d74c60 (hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.106831: dwc3_gadget_giveback: ep2in: req ed6c9800 length 1024/1024 zsI ==> 0 irq/456-dwc3-2104 [001] d... 77.106836: dwc3_ep_queue: ep2in: req ed6c9800 length 0/1024 zsI ==> -115 irq/456-dwc3-2104 [001] d... 77.106949: dwc3_event: event (a75e408a): ep2in: Transfer In-Progress irq/456-dwc3-2104 [001] d... 77.106951: dwc3_complete_trb: ep2in: 0/4 trb f22a2070 buf 00000000ad27b800 size 0 ctrl 29d78c60 (hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 77.106956: dwc3_gadget_giveback: ep2in: req ed6c9600 length 1024/1024 zsI ==> 0 irq/456-dwc3-2104 [001] d... 77.106961: dwc3_ep_queue: ep2in: req ed6c9600 length 0/1024 zsI ==> -115 irq/456-dwc3-2104 [001] d... 77.106970: dwc3_gadget_ep_cmd: ep2in: cmd 'End Transfer' [331016] params 00000000 00000000 00000000 --> status: Successful irq/456-dwc3-2104 [001] d... 77.107117: dwc3_event: event (080501ca): ep2in: Endpoint Command Complete irq/456-dwc3-2104 [001] d... 77.107120: dwc3_event: event (a75f10ca): ep2in: Transfer Not Ready (Not Active) ################################# #Bad case. Line 12797 in pastebin [2] ################################# irq/456-dwc3-2104 [001] d... 101.443723: dwc3_gadget_ep_cmd: ep2in: cmd 'Set Endpoint Configuration' [1025] params 00042002 0a000600 00000000 --> status: Successful irq/456-dwc3-2104 [001] d... 101.443734: dwc3_gadget_ep_enable: ep2in: mps 1024/1024 streams 15 burst 0 ring 0/0 flags E:swbpm:e:< irq/456-dwc3-2104 [001] d... 101.443753: dwc3_event: event (000020c2): ep0in: Transfer Not Ready (Not Active) [Status Phase] uvc-gadget-2107 [000] .... 101.450760: dwc3_alloc_request: ep2in: req ed1dd680 length 0/0 zsI ==> 0 uvc-gadget-2107 [000] .... 101.450768: dwc3_alloc_request: ep2in: req ed1dd500 length 0/0 zsI ==> 0 uvc-gadget-2107 [000] .... 101.450771: dwc3_alloc_request: ep2in: req ed1dd480 length 0/0 zsI ==> 0 uvc-gadget-2107 [000] .... 101.450774: dwc3_alloc_request: ep2in: req ed1dd600 length 0/0 zsI ==> 0 uvc-gadget-2107 [000] d... 101.450783: dwc3_ep_queue: ep2in: req ed1dd680 length 0/1024 zsI ==> -115 uvc-gadget-2107 [000] d... 101.450794: dwc3_ep_queue: ep2in: req ed1dd500 length 0/1024 zsI ==> -115 uvc-gadget-2107 [000] d... 101.450801: dwc3_ep_queue: ep2in: req ed1dd480 length 0/1024 zsI ==> -115 uvc-gadget-2107 [000] d... 101.450808: dwc3_ep_queue: ep2in: req ed1dd600 length 0/1024 zsI ==> -115 uvc-gadget-2107 [000] dn.. 101.450846: dwc3_prepare_trb: ep0in: 0/0 trb f224f000 buf 00000000fd858000 size 0 ctrl 00000c33 (HLcs:SC:status2) uvc-gadget-2107 [000] dn.. 101.450856: dwc3_gadget_ep_cmd: ep0in: cmd 'Start Transfer' [1030] params 00000000 fd859000 00000000 --> status: Successful irq/456-dwc3-2104 [001] d... 101.450921: dwc3_event: event (0000c042): ep0in: Transfer Complete [Status Phase] irq/456-dwc3-2104 [001] d... 101.450924: dwc3_complete_trb: ep0out: 0/2 trb f224f000 buf 00000000fd858000 size 0 ctrl 00000c32 (hLcs:SC:status2) irq/456-dwc3-2104 [001] d... 101.450929: dwc3_gadget_giveback: ep0out: req ed516700 length 0/0 zsI ==> 0 irq/456-dwc3-2104 [001] d... 101.450935: dwc3_prepare_trb: ep0out: 0/2 trb f224f000 buf 00000000fd858000 size 8 ctrl 00000c23 (HLcs:SC:setup) irq/456-dwc3-2104 [001] d... 101.450943: dwc3_gadget_ep_cmd: ep0out: cmd 'Start Transfer' [1030] params 00000000 fd859000 00000000 --> status: Successful uvc-gadget-2107 [000] d... 101.450969: dwc3_gadget_ep_cmd: ep0out: cmd 'Set Stall' [1028] params 00000000 00000000 00000000 --> status: Successful uvc-gadget-2107 [000] d... 101.450974: dwc3_prepare_trb: ep0out: 0/2 trb f224f000 buf 00000000fd858000 size 8 ctrl 00000c23 (HLcs:SC:setup) uvc-gadget-2107 [000] d... 101.450983: dwc3_gadget_ep_cmd: ep0out: cmd 'Start Transfer' [1030] params 00000000 fd859000 00000000 --> status: No Resource irq/456-dwc3-2104 [001] d... 101.654528: dwc3_event: event (203710ca): ep2in: Transfer Not Ready (Not Active) irq/456-dwc3-2104 [001] d... 101.654535: dwc3_prepare_trb: ep2in: 1/4 trb f22a2000 buf 00000000ad27b800 size 1024 ctrl 00000c61 (Hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 101.654540: dwc3_prepare_trb: ep2in: 2/4 trb f22a2010 buf 00000000ad524400 size 1024 ctrl 00000c61 (Hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 101.654544: dwc3_prepare_trb: ep2in: 3/4 trb f22a2020 buf 00000000ac9b4000 size 1024 ctrl 00000c61 (Hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 101.654549: dwc3_prepare_trb: ep2in: 4/4 trb f22a2030 buf 00000000ac9b4400 size 1024 ctrl 00000c61 (Hlcs:SC:isoc-first) irq/456-dwc3-2104 [001] d... 101.654557: dwc3_gadget_ep_cmd: ep2in: cmd 'Start Transfer' [540738566] params 00000000 fd86b000 00000000 --> status: Bus Expiry irq/456-dwc3-2104 [001] d... 101.654559: dwc3_gadget_giveback: ep2in: req ed1dd680 length 0/1024 zsI ==> -11 uvc-gadget-2107 [000] d... 101.664841: dwc3_ep_queue: ep2in: req ed1dd680 length 0/1024 zsI ==> -115 -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
