You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@nuttx.apache.org by GitBox <gi...@apache.org> on 2021/03/24 08:06:22 UTC
[GitHub] [incubator-nuttx] PetteriAimonen opened a new pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
PetteriAimonen opened a new pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163
## Summary
Sometimes Windows would send RNDIS_KEEPALIVE_MSG and RNDIS_QUERY_MSG close to each other. This would cause the latter command to overwrite the reply for the prior command. This in turn will cause Windows to drop the connection after a 20 second timeout.
Easy way to reproduce the issue is to open the Windows "Adapter Status" dialog that shows the realtime TX/RX byte counts. This causes multiple RNDIS_QUERY_MSGs per second, and the connection will drop in less than an hour.
This commit fixes this issue, and other potential race conditions (such as USB descriptor read in middle on RNDIS query) by using a separate queue for the reply packets.
Example USB trace:
<pre>
13:21:14.104859 | usb_packet-1: SETUP ADDR 1 EP 0 <---- Host starts 04 RNDIS_QUERY_MSG request
13:21:14.104862 | usb_packet-1: DATA0 [ 21 00 00 00 00 00 4C 00 ]
13:21:14.104871 | usb_packet-1: ACK
13:21:14.104878 | usb_packet-1: IN ADDR 1 EP 1
13:21:14.104881 | usb_packet-1: NAK
| Previous two lines repeated 170 times
13:21:14.105847 | usb_packet-1: SOF 750
13:21:14.105850 | usb_packet-1: IN ADDR 1 EP 3
13:21:14.105853 | usb_packet-1: NAK
13:21:14.105859 | usb_packet-1: OUT ADDR 1 EP 0
13:21:14.105863 | usb_packet-1: DATA1 [ 04 00 00 00 4C 00 00 00 BC 03 00 00 02 01 02 00 30 00 00 00 14 00 00 00 00 00 00 00 AB 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ]
13:21:14.105908 | usb_packet-1: NAK
13:21:14.105916 | usb_packet-1: IN ADDR 1 EP 1
| Previous two lines repeated 163 times
13:21:14.106847 | usb_packet-1: SOF 751
13:21:14.106850 | usb_packet-1: IN ADDR 1 EP 3
13:21:14.106853 | usb_packet-1: NAK
13:21:14.106860 | usb_packet-1: OUT ADDR 1 EP 0
13:21:14.106863 | usb_packet-1: DATA1 [ 04 00 00 00 4C 00 00 00 BC 03 00 00 02 01 02 00 30 00 00 00 14 00 00 00 00 00 00 00 AB 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ]
13:21:14.106909 | usb_packet-1: ACK <---------- 04 RNDIS_QUERY_MSG first packet received
13:21:14.106916 | usb_packet-1: IN ADDR 1 EP 1
13:21:14.106919 | usb_packet-1: NAK
| Previous two lines repeated 162 times
13:21:14.107847 | usb_packet-1: SOF 752
13:21:14.107850 | usb_packet-1: IN ADDR 1 EP 3
13:21:14.107854 | usb_packet-1: DATA0 [ 01 00 00 00 00 00 00 00 ]
13:21:14.107863 | usb_packet-1: ACK <------- Interrupt endpoint notification that command result is available.
13:21:14.107868 | usb_packet-1: OUT ADDR 1 EP 0
13:21:14.107871 | usb_packet-1: DATA0 [ 00 00 00 00 00 00 00 00 00 00 00 00 ]
13:21:14.107883 | usb_packet-1: ACK <---- Delayed last 12 bytes (separate bug #3162)
13:21:14.107890 | usb_packet-1: IN ADDR 1 EP 1
13:21:14.107893 | usb_packet-1: NAK
| Previous two lines repeated 168 times
....
13:21:14.109848 | usb_packet-1: SOF 754
13:21:14.109851 | usb_packet-1: IN ADDR 1 EP 3
13:21:14.109854 | usb_packet-1: NAK
13:21:14.109860 | usb_packet-1: SETUP ADDR 1 EP 0 <---- Host starts 08 RNDIS_KEEPALIVE_MSG
13:21:14.109863 | usb_packet-1: DATA0 [ 21 00 00 00 00 00 0C 00 ]
13:21:14.109872 | usb_packet-1: ACK
13:21:14.109879 | usb_packet-1: IN ADDR 1 EP 1
13:21:14.109883 | usb_packet-1: NAK
| Previous two lines repeated 170 times
13:21:14.110848 | usb_packet-1: SOF 755
13:21:14.110851 | usb_packet-1: IN ADDR 1 EP 3
13:21:14.110855 | usb_packet-1: NAK
13:21:14.110861 | usb_packet-1: OUT ADDR 1 EP 0
13:21:14.110864 | usb_packet-1: DATA1 [ 08 00 00 00 0C 00 00 00 BD 03 00 00 ]
13:21:14.110875 | usb_packet-1: NAK
13:21:14.110882 | usb_packet-1: IN ADDR 1 EP 1
| Previous two lines repeated 171 times
13:21:14.111848 | usb_packet-1: SOF 756
13:21:14.111852 | usb_packet-1: IN ADDR 1 EP 3
13:21:14.111855 | usb_packet-1: NAK
13:21:14.111861 | usb_packet-1: OUT ADDR 1 EP 0
13:21:14.111864 | usb_packet-1: DATA1 [ 08 00 00 00 0C 00 00 00 BD 03 00 00 ]
13:21:14.111876 | usb_packet-1: ACK <--- RNDIS_KEEPALIVE_MSG complete
13:21:14.111883 | usb_packet-1: IN ADDR 1 EP 1
13:21:14.111886 | usb_packet-1: NAK
| Previous two lines repeated 170 times
13:21:14.112849 | usb_packet-1: SOF 757
13:21:14.112852 | usb_packet-1: IN ADDR 1 EP 3
13:21:14.112855 | usb_packet-1: DATA1 [ 01 00 00 00 00 00 00 00 ]
13:21:14.112864 | usb_packet-1: ACK <--- Notification of command result available
13:21:14.112869 | usb_packet-1: IN ADDR 1 EP 0
13:21:14.112872 | usb_packet-1: DATA1 [ ]
13:21:14.112875 | usb_packet-1: ACK
13:21:14.112882 | usb_packet-1: IN ADDR 1 EP 1
13:21:14.112885 | usb_packet-1: NAK
...
13:21:14.116861 | usb_packet-1: IN ADDR 1 EP 0
13:21:14.116865 | usb_packet-1: DATA1 [ 08 00 00 80 10 00 00 00 BD 03 00 00 00 00 00 00 ]
13:21:14.116879 | usb_packet-1: ACK <---- Got 08 RNDIS_KEEPALIVE_MSG response, the earlier 04 has been overwritten.
</pre>
## Impact
This improves reliability of RNDIS communications. In our use case, the problem only occurred once in several days unless the Network Adapter Status dialog was open. So the race condition is quite rare in normal usage.
## Testing
Tested on custom STM32F4 board with USB RNDIS driver.
The bug can be easiest reproduced by opening the Windows network adapter statistics
window, which causes concurrent RNDIS requests. Note that on STM32 #3162 also occurs
in this situation.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] masayuki2009 commented on pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
masayuki2009 commented on pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163#issuecomment-806907785
@PetteriAimonen
[spresense-rndis-failed-20210325.pcapng.gz](https://github.com/apache/incubator-nuttx/files/6205668/spresense-rndis-failed-20210325.pcapng.gz)
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] PetteriAimonen commented on pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
PetteriAimonen commented on pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163#issuecomment-808032774
@masayuki2009 I think this may be related to unaligned access to response_queue. This depends on optimization settings and struct layout, which is why it didn't occur in our configuration. If this is the cause, you should be seeing hardfault due to unaligned access.
I'm working on a proper fix.
In the meanwhile, can you try this to check: in `drivers/usbdev/rndis.c` change the order of variables `response_queue_bytes` and `response_queue` so that `response_queue` comes first:
<pre>
size_t response_queue_bytes; /* Count of bytes waiting in response_queue. */
uint8_t response_queue[RNDIS_RESP_QUEUE_LEN];
</pre>
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] acassis commented on a change in pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
acassis commented on a change in pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163#discussion_r600718552
##########
File path: drivers/usbdev/rndis.c
##########
@@ -2474,20 +2498,19 @@ static int usbclass_setup(FAR struct usbdevclass_driver_s *driver,
}
else if (ctrl->req == RNDIS_GET_ENCAPSULATED_RESPONSE)
{
- if (!priv->ctrlreq_has_encap_response)
+ if (priv->response_queue_bytes == 0)
{
+ /* No reply available is indicated with a single 0x00 byte. */
ret = 1;
ctrlreq->buf[0] = 0;
}
else
{
- /* There is data prepared in the ctrlreq buffer.
- * Just assign the length.
- */
-
+ /* Retrieve a single reply from the response queue to control request buffer. */
Review comment:
Yes, you are right! I was looking the first two commits only
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] masayuki2009 commented on pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
masayuki2009 commented on pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163#issuecomment-806860666
@PetteriAimonen
```
[ 3030.289521] usb 3-4.2: new high-speed USB device number 18 using xhci_hcd
[ 3030.395649] usb 3-4.2: New USB device found, idVendor=584e, idProduct=5342
[ 3030.395652] usb 3-4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 3030.395654] usb 3-4.2: Product: RNDIS gadget
[ 3030.395655] usb 3-4.2: Manufacturer: NuttX
[ 3030.395656] usb 3-4.2: SerialNumber: 1234
[ 3030.399068] rndis_host 3-4.2:1.0: skipping garbage
[ 3074.187958] rndis_host 3-4.2:1.0: RNDIS init failed, -110
[ 3074.188002] rndis_host: probe of 3-4.2:1.0 failed with error -110
[ 3074.188430] rndis_wlan 3-4.2:1.0: skipping garbage
[ 3079.260746] rndis_wlan 3-4.2:1.0: RNDIS init failed, -110
[ 3079.261069] rndis_wlan: probe of 3-4.2:1.0 failed with error -110
[ 3079.261722] usb 3-4.2: USB disconnect, device number 18
[ 3079.492258] usb 3-4.2: new high-speed USB device number 19 using xhci_hcd
[ 3079.595589] usb 3-4.2: New USB device found, idVendor=584e, idProduct=5342
[ 3079.595592] usb 3-4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 3079.595594] usb 3-4.2: Product: RNDIS gadget
[ 3079.595595] usb 3-4.2: Manufacturer: NuttX
[ 3079.595596] usb 3-4.2: SerialNumber: 1234
[ 3079.598378] rndis_host 3-4.2:1.0: skipping garbage
[ 3130.234042] rndis_host 3-4.2:1.0: RNDIS init failed, -110
[ 3130.234181] rndis_host: probe of 3-4.2:1.0 failed with error -110
[ 3130.235879] rndis_wlan 3-4.2:1.0: skipping garbage
[ 3135.238601] rndis_wlan 3-4.2:1.0: RNDIS init failed, -71
[ 3135.239154] rndis_wlan: probe of 3-4.2:1.0 failed with error -71
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] PetteriAimonen commented on pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
PetteriAimonen commented on pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163#issuecomment-806798892
I have tested on Linux (5.7.0) and Windows 10 hosts.
But I have only full-speed interface.
I don't think this should cause worse behavior even without #3162 fix.
My patch for that applies only for otgfsdev, though I'm not sure if there is even any problem with HS as max packet size is 512 bytes there.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] masayuki2009 commented on pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
masayuki2009 commented on pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163#issuecomment-806765003
Hi @PetteriAimonen @acassis
Hmmm, I noticed that spresense:rndis does not work with Linux RNDIS host with this PR.
Did you test this PR with a Linux Host?
Also, did you test this PR with a high-speed USB controller?
May I revert this PR so that I can continue daily testing?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] masayuki2009 edited a comment on pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
masayuki2009 edited a comment on pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163#issuecomment-806872035
@PetteriAimonen
With dynamic debug options
[ 4774.329469] usb 3-4.2: new high-speed USB device number 23 using xhci_hcd
[ 4774.329479] xhci_hcd 0000:03:00.0: Set root hub portnum to 8
[ 4774.329481] xhci_hcd 0000:03:00.0: Set fake root hub portnum to 4
[ 4774.329483] xhci_hcd 0000:03:00.0: udev->tt = (null)
[ 4774.329485] xhci_hcd 0000:03:00.0: udev->ttport = 0x0
[ 4774.329489] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4774.329593] xhci_hcd 0000:03:00.0: Successful setup context command
[ 4774.329627] xhci_hcd 0000:03:00.0: Op regs DCBAA ptr = 0x0000022bbbc000
[ 4774.329630] xhci_hcd 0000:03:00.0: Slot ID 8 dcbaa entry @00000000ff58fafd = 0x000001eb32c000
[ 4774.329632] xhci_hcd 0000:03:00.0: Output Context DMA address = 0x1eb32c000
[ 4774.329634] xhci_hcd 0000:03:00.0: Internal device address = 0
[ 4774.329969] xhci_hcd 0000:03:00.0: Waiting for status stage event
[ 4774.414519] xhci_hcd 0000:03:00.0: Resetting device with slot ID 8
[ 4774.414526] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4774.414607] xhci_hcd 0000:03:00.0: Completed reset device command.
[ 4774.414630] xhci_hcd 0000:03:00.0: Successful reset device command.
[ 4774.414640] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4774.414723] xhci_hcd 0000:03:00.0: Successful setup address command
[ 4774.414735] xhci_hcd 0000:03:00.0: Op regs DCBAA ptr = 0x0000022bbbc000
[ 4774.414739] xhci_hcd 0000:03:00.0: Slot ID 8 dcbaa entry @00000000ff58fafd = 0x000001eb32c000
[ 4774.414741] xhci_hcd 0000:03:00.0: Output Context DMA address = 0x1eb32c000
[ 4774.414742] xhci_hcd 0000:03:00.0: Internal device address = 0
[ 4774.414746] xhci_hcd 0000:03:00.0: Endpoint 0x0 ep reset callback called
[ 4774.434987] usb 3-4.2: skipped 1 descriptor after configuration
[ 4774.435494] xhci_hcd 0000:03:00.0: Waiting for status stage event
[ 4774.435530] usb 3-4.2: default language 0x0409
[ 4774.435892] xhci_hcd 0000:03:00.0: Waiting for status stage event
[ 4774.436226] xhci_hcd 0000:03:00.0: Waiting for status stage event
[ 4774.436597] xhci_hcd 0000:03:00.0: Waiting for status stage event
[ 4774.436634] usb 3-4.2: udev 23, busnum 3, minor = 278
[ 4774.436637] usb 3-4.2: New USB device found, idVendor=584e, idProduct=5342
[ 4774.436639] usb 3-4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 4774.436640] usb 3-4.2: Product: RNDIS gadget
[ 4774.436642] usb 3-4.2: Manufacturer: NuttX
[ 4774.436644] usb 3-4.2: SerialNumber: 1234
[ 4774.436865] usb 3-4.2: usb_probe_device
[ 4774.436873] usb 3-4.2: configuration #1 chosen from 1 choice
[ 4774.436910] xhci_hcd 0000:03:00.0: add ep 0x83, slot id 8, new drop flags = 0x0, new add flags = 0x80
[ 4774.437036] xhci_hcd 0000:03:00.0: add ep 0x81, slot id 8, new drop flags = 0x0, new add flags = 0x88
[ 4774.437056] xhci_hcd 0000:03:00.0: add ep 0x2, slot id 8, new drop flags = 0x0, new add flags = 0x98
[ 4774.437060] xhci_hcd 0000:03:00.0: xhci_check_bandwidth called for udev 000000005b9abb34
[ 4774.437066] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4774.437169] xhci_hcd 0000:03:00.0: Successful Endpoint Configure command
[ 4774.437173] xhci_hcd 0000:03:00.0: Endpoint 0x83 ep reset callback called
[ 4774.437176] xhci_hcd 0000:03:00.0: Endpoint 0x81 ep reset callback called
[ 4774.437177] xhci_hcd 0000:03:00.0: Endpoint 0x2 ep reset callback called
[ 4774.439980] usb 3-4.2: adding 3-4.2:1.0 (config #1, interface 0)
[ 4774.440061] rndis_host 3-4.2:1.0: usb_probe_interface
[ 4774.440064] rndis_host 3-4.2:1.0: usb_probe_interface - got id
[ 4774.440094] rndis_host 3-4.2:1.0: CDC descriptors on config
[ 4774.440095] rndis_host 3-4.2:1.0: skipping garbage
[ 4779.527193] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4779.527214] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4779.527224] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4779.527226] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4779.527228] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4779.527231] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4779.527233] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b6200 (DMA)
[ 4779.527235] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4779.527238] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 000000001af73fa9 (0x1b69b6200 dma), new cycle = 1
[ 4779.527240] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4779.527264] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4779.527282] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4779.527286] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b6200
[ 4779.527449] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4784.650199] xhci_hcd 0000:03:00.0: Cancel URB 00000000078eac48, dev 4.2, ep 0x0, starting at offset 0x1b69b6200
[ 4784.650208] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4784.650297] xhci_hcd 0000:03:00.0: Removing canceled TD starting at 0x1b69b6200 (dma).
[ 4784.650330] usb 3-4.2: kworker/1:3 timed out on ep0in len=0/1025
[ 4784.650336] rndis_host 3-4.2:1.0: rndis response error, code -110
[ 4789.769573] xhci_hcd 0000:03:00.0: Cancel URB 00000000078eac48, dev 4.2, ep 0x0, starting at offset 0x1b69b6230
[ 4789.769582] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4789.769668] xhci_hcd 0000:03:00.0: Removing canceled TD starting at 0x1b69b6230 (dma).
[ 4789.769704] usb 3-4.2: kworker/1:3 timed out on ep0in len=0/1025
[ 4789.769709] rndis_host 3-4.2:1.0: rndis response error, code -110
[ 4794.841288] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4794.841309] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4794.841321] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4794.841323] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4794.841326] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4794.841329] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4794.841332] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b6290 (DMA)
[ 4794.841333] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4794.841337] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 0000000010751fbb (0x1b69b6290 dma), new cycle = 1
[ 4794.841340] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4794.841369] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4794.841383] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4794.841386] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b6290
[ 4794.841522] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4799.921970] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4799.921990] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4799.922000] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4799.922002] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4799.922004] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4799.922006] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4799.922008] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b62c0 (DMA)
[ 4799.922010] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4799.922013] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 00000000053b82dd (0x1b69b62c0 dma), new cycle = 1
[ 4799.922015] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4799.922037] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4799.922072] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4799.922076] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b62c0
[ 4799.922252] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4805.055884] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4805.055889] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4805.055893] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4805.055894] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4805.055895] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4805.055896] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4805.055897] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b62f0 (DMA)
[ 4805.055898] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4805.055899] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 00000000fc7e419b (0x1b69b62f0 dma), new cycle = 1
[ 4805.055900] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4805.055914] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4805.055931] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4805.055933] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b62f0
[ 4805.056017] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4810.157679] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4810.157698] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4810.157707] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4810.157709] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4810.157711] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4810.157714] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4810.157716] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b6320 (DMA)
[ 4810.157717] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4810.157720] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 000000009e494531 (0x1b69b6320 dma), new cycle = 1
[ 4810.157722] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4810.157745] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4810.157777] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4810.157781] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b6320
[ 4810.158085] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4815.273722] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4815.273738] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4815.273744] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4815.273746] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4815.273748] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4815.273750] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4815.273752] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b6350 (DMA)
[ 4815.273753] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4815.273755] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 00000000c2a8a2a8 (0x1b69b6350 dma), new cycle = 1
[ 4815.273757] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4815.273774] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4815.273797] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4815.273800] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b6350
[ 4815.274589] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4820.321872] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4820.321894] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4820.321902] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4820.321904] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4820.321906] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4820.321909] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4820.321911] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b6380 (DMA)
[ 4820.321912] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4820.321916] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 000000009ef42c82 (0x1b69b6380 dma), new cycle = 1
[ 4820.321918] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4820.321940] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4820.321972] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4820.321976] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b6380
[ 4820.322286] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4825.456116] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4825.456136] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4825.456145] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4825.456148] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4825.456149] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4825.456152] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4825.456154] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b63b0 (DMA)
[ 4825.456156] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4825.456159] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 00000000f3da1c0b (0x1b69b63b0 dma), new cycle = 1
[ 4825.456161] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4825.456184] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4825.456218] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4825.456223] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b63b0
[ 4825.456529] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4825.504907] rndis_host 3-4.2:1.0: rndis response timeout
[ 4825.504911] rndis_host 3-4.2:1.0: RNDIS init failed, -110
[ 4825.504954] rndis_host: probe of 3-4.2:1.0 failed with error -110
[ 4825.504976] rndis_wlan 3-4.2:1.0: usb_probe_interface
[ 4825.504980] rndis_wlan 3-4.2:1.0: usb_probe_interface - got id
[ 4825.505106] rndis_wlan 3-4.2:1.0: CDC descriptors on config
[ 4825.505108] rndis_wlan 3-4.2:1.0: skipping garbage
[ 4830.505802] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4830.505823] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4830.505831] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4830.505834] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4830.505836] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4830.505839] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4830.505841] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b63e0 (DMA)
[ 4830.505842] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4830.505845] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 00000000e3da8459 (0x1b69b63e0 dma), new cycle = 1
[ 4830.505847] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4830.505869] xhci_hcd 0000:03:00.0: Giveback URB 00000000437ac163, len = 0, expected = 24, status = -71
[ 4830.505901] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4830.505905] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b63e0
[ 4830.506263] rndis_wlan 3-4.2:1.0: RNDIS init failed, -71
[ 4830.506358] rndis_wlan: probe of 3-4.2:1.0 failed with error -71
[ 4830.506407] usb 3-4.2: adding 3-4.2:1.1 (config #1, interface 1)
[ 4830.506587] hub 3-4:1.0: state 7 ports 7 chg 0000 evt 0004
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] acassis commented on a change in pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
acassis commented on a change in pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163#discussion_r600423373
##########
File path: drivers/usbdev/rndis.c
##########
@@ -1384,11 +1389,16 @@ rndis_prepare_response(FAR struct rndis_dev_s *priv, size_t size,
*
****************************************************************************/
-static int rndis_send_encapsulated_response(FAR struct rndis_dev_s *priv)
+static int rndis_send_encapsulated_response(FAR struct rndis_dev_s *priv, size_t size)
{
FAR struct rndis_notification *notif =
(FAR struct rndis_notification *)priv->epintin_req->buf;
+ /* Mark the response as available in the queue */
+ priv->response_queue_bytes += size;
Review comment:
Please include an empty line after the comment line, it is part of the Coding Style.
##########
File path: drivers/usbdev/rndis.c
##########
@@ -1384,11 +1389,16 @@ rndis_prepare_response(FAR struct rndis_dev_s *priv, size_t size,
*
****************************************************************************/
-static int rndis_send_encapsulated_response(FAR struct rndis_dev_s *priv)
+static int rndis_send_encapsulated_response(FAR struct rndis_dev_s *priv, size_t size)
{
FAR struct rndis_notification *notif =
(FAR struct rndis_notification *)priv->epintin_req->buf;
+ /* Mark the response as available in the queue */
+ priv->response_queue_bytes += size;
+ DEBUGASSERT(priv->response_queue_bytes <= RNDIS_RESP_QUEUE_LEN);
+
+ /* Send notification on IRQ endpoint, to tell host to read the data. */
Review comment:
Ditto
##########
File path: drivers/usbdev/rndis.c
##########
@@ -1738,15 +1746,27 @@ static void rndis_wrcomplete(FAR struct usbdev_ep_s *ep,
static void usbclass_ep0incomplete(FAR struct usbdev_ep_s *ep,
FAR struct usbdev_req_s *req)
{
+ struct rndis_dev_s *priv = (FAR struct rndis_dev_s *)ep->priv;
if (req->result || req->xfrd != req->len)
{
usbtrace(TRACE_CLSERROR(USBSER_TRACEERR_REQRESULT),
(uint16_t)-req->result);
}
- else if (req->len > 0)
+ else if (req->len > 0 && req->priv == priv->response_queue)
{
- struct rndis_dev_s *priv = (FAR struct rndis_dev_s *)ep->priv;
- priv->ctrlreq_has_encap_response = false;
+ /* This transfer was from the response queue, subtract remaining byte count. */
+ req->priv = 0;
Review comment:
Please add an empty line before and after the comment line.
##########
File path: drivers/usbdev/rndis.c
##########
@@ -1738,15 +1746,27 @@ static void rndis_wrcomplete(FAR struct usbdev_ep_s *ep,
static void usbclass_ep0incomplete(FAR struct usbdev_ep_s *ep,
FAR struct usbdev_req_s *req)
{
+ struct rndis_dev_s *priv = (FAR struct rndis_dev_s *)ep->priv;
if (req->result || req->xfrd != req->len)
{
usbtrace(TRACE_CLSERROR(USBSER_TRACEERR_REQRESULT),
(uint16_t)-req->result);
}
- else if (req->len > 0)
+ else if (req->len > 0 && req->priv == priv->response_queue)
{
- struct rndis_dev_s *priv = (FAR struct rndis_dev_s *)ep->priv;
- priv->ctrlreq_has_encap_response = false;
+ /* This transfer was from the response queue, subtract remaining byte count. */
+ req->priv = 0;
+ if (req->len >= priv->response_queue_bytes)
+ {
+ /* Queue now empty */
+ priv->response_queue_bytes = 0;
+ }
+ else
+ {
+ /* Copy the remaining responses to beginning of buffer. */
Review comment:
Ditto
##########
File path: drivers/usbdev/rndis.c
##########
@@ -1738,15 +1746,27 @@ static void rndis_wrcomplete(FAR struct usbdev_ep_s *ep,
static void usbclass_ep0incomplete(FAR struct usbdev_ep_s *ep,
FAR struct usbdev_req_s *req)
{
+ struct rndis_dev_s *priv = (FAR struct rndis_dev_s *)ep->priv;
if (req->result || req->xfrd != req->len)
{
usbtrace(TRACE_CLSERROR(USBSER_TRACEERR_REQRESULT),
(uint16_t)-req->result);
}
- else if (req->len > 0)
+ else if (req->len > 0 && req->priv == priv->response_queue)
{
- struct rndis_dev_s *priv = (FAR struct rndis_dev_s *)ep->priv;
- priv->ctrlreq_has_encap_response = false;
+ /* This transfer was from the response queue, subtract remaining byte count. */
+ req->priv = 0;
+ if (req->len >= priv->response_queue_bytes)
+ {
+ /* Queue now empty */
+ priv->response_queue_bytes = 0;
Review comment:
Ditto
##########
File path: drivers/usbdev/rndis.c
##########
@@ -2194,6 +2214,9 @@ static int usbclass_bind(FAR struct usbdevclass_driver_s *driver,
leave_critical_section(flags);
}
+ /* Initialize response queue to empty */
+ priv->response_queue_bytes = 0;
Review comment:
Ditto
##########
File path: drivers/usbdev/rndis.c
##########
@@ -2474,20 +2498,19 @@ static int usbclass_setup(FAR struct usbdevclass_driver_s *driver,
}
else if (ctrl->req == RNDIS_GET_ENCAPSULATED_RESPONSE)
{
- if (!priv->ctrlreq_has_encap_response)
+ if (priv->response_queue_bytes == 0)
{
+ /* No reply available is indicated with a single 0x00 byte. */
ret = 1;
ctrlreq->buf[0] = 0;
}
else
{
- /* There is data prepared in the ctrlreq buffer.
- * Just assign the length.
- */
-
+ /* Retrieve a single reply from the response queue to control request buffer. */
Review comment:
Ditto
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] PetteriAimonen commented on a change in pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
PetteriAimonen commented on a change in pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163#discussion_r600430492
##########
File path: drivers/usbdev/rndis.c
##########
@@ -1384,11 +1389,16 @@ rndis_prepare_response(FAR struct rndis_dev_s *priv, size_t size,
*
****************************************************************************/
-static int rndis_send_encapsulated_response(FAR struct rndis_dev_s *priv)
+static int rndis_send_encapsulated_response(FAR struct rndis_dev_s *priv, size_t size)
{
FAR struct rndis_notification *notif =
(FAR struct rndis_notification *)priv->epintin_req->buf;
+ /* Mark the response as available in the queue */
+ priv->response_queue_bytes += size;
Review comment:
Hmm, I already added the empty lines after the style check complained. Are they not visible for you?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] PetteriAimonen commented on pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
PetteriAimonen commented on pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163#issuecomment-806867722
Would you be able to take an USB trace with Wireshark?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] masayuki2009 commented on pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
masayuki2009 commented on pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163#issuecomment-808042690
@PetteriAimonen
Thanks!
It works now.
```
diff --git a/drivers/usbdev/rndis.c b/drivers/usbdev/rndis.c
index 166b768b8d..65c35639dc 100644
--- a/drivers/usbdev/rndis.c
+++ b/drivers/usbdev/rndis.c
@@ -174,8 +174,8 @@ struct rndis_dev_s
uint32_t rndis_host_rx_count; /* RX packet counter */
uint8_t host_mac_address[6]; /* Host side MAC address */
- uint8_t response_queue[RNDIS_RESP_QUEUE_LEN];
size_t response_queue_bytes; /* Count of bytes waiting in response_queue. */
+ uint8_t response_queue[RNDIS_RESP_QUEUE_LEN];
};
/* The internal version of the class driver */
```
```
[64231.795782] usb 3-4.2: USB disconnect, device number 21
[64231.795920] rndis_host 3-4.2:1.0 enxa0e0deadbeff: unregister 'rndis_host' usb-0000:03:00.0-4.2, RNDIS device
[64236.203169] usb 3-4.2: new high-speed USB device number 22 using xhci_hcd
[64236.318499] usb 3-4.2: New USB device found, idVendor=584e, idProduct=5342
[64236.318502] usb 3-4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[64236.318503] usb 3-4.2: Product: RNDIS gadget
[64236.318505] usb 3-4.2: Manufacturer: NuttX
[64236.318506] usb 3-4.2: SerialNumber: 1234
[64236.327639] rndis_host 3-4.2:1.0: skipping garbage
[64236.333227] rndis_host 3-4.2:1.0 eth0: register 'rndis_host' at usb-0000:03:00.0-4.2, RNDIS device, a0:e0:de:ad:be:ff
[64236.413364] rndis_host 3-4.2:1.0 enxa0e0deadbeff: renamed from eth0
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] PetteriAimonen commented on pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
PetteriAimonen commented on pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163#issuecomment-806808939
@masayuki2009 Can you post `dmesg` log?
These dynamic debug options can also give more information:
echo -n 'file *usb* +p' > /sys/kernel/debug/dynamic_debug/control
echo -n 'file *cdc_ether* +p' > /sys/kernel/debug/dynamic_debug/control
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] acassis merged pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
acassis merged pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] masayuki2009 edited a comment on pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
masayuki2009 edited a comment on pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163#issuecomment-806765003
Hi @PetteriAimonen @acassis
Hmmm, I noticed that spresense:rndis does not work with Linux RNDIS host with this PR.
Did you test this PR with a Linux Host?
Also, did you test this PR with a high-speed USB controller?
Let me revert this PR so that I can continue daily testing.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] PetteriAimonen commented on pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
PetteriAimonen commented on pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163#issuecomment-806910096
@masayuki2009 Thanks! I'll take a look tomorrow.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [incubator-nuttx] masayuki2009 commented on pull request #3163: USBDEV RNDIS: Fix occasional disconnections due to race condition
Posted by GitBox <gi...@apache.org>.
masayuki2009 commented on pull request #3163:
URL: https://github.com/apache/incubator-nuttx/pull/3163#issuecomment-806872035
[ 4774.329469] usb 3-4.2: new high-speed USB device number 23 using xhci_hcd
[ 4774.329479] xhci_hcd 0000:03:00.0: Set root hub portnum to 8
[ 4774.329481] xhci_hcd 0000:03:00.0: Set fake root hub portnum to 4
[ 4774.329483] xhci_hcd 0000:03:00.0: udev->tt = (null)
[ 4774.329485] xhci_hcd 0000:03:00.0: udev->ttport = 0x0
[ 4774.329489] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4774.329593] xhci_hcd 0000:03:00.0: Successful setup context command
[ 4774.329627] xhci_hcd 0000:03:00.0: Op regs DCBAA ptr = 0x0000022bbbc000
[ 4774.329630] xhci_hcd 0000:03:00.0: Slot ID 8 dcbaa entry @00000000ff58fafd = 0x000001eb32c000
[ 4774.329632] xhci_hcd 0000:03:00.0: Output Context DMA address = 0x1eb32c000
[ 4774.329634] xhci_hcd 0000:03:00.0: Internal device address = 0
[ 4774.329969] xhci_hcd 0000:03:00.0: Waiting for status stage event
[ 4774.414519] xhci_hcd 0000:03:00.0: Resetting device with slot ID 8
[ 4774.414526] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4774.414607] xhci_hcd 0000:03:00.0: Completed reset device command.
[ 4774.414630] xhci_hcd 0000:03:00.0: Successful reset device command.
[ 4774.414640] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4774.414723] xhci_hcd 0000:03:00.0: Successful setup address command
[ 4774.414735] xhci_hcd 0000:03:00.0: Op regs DCBAA ptr = 0x0000022bbbc000
[ 4774.414739] xhci_hcd 0000:03:00.0: Slot ID 8 dcbaa entry @00000000ff58fafd = 0x000001eb32c000
[ 4774.414741] xhci_hcd 0000:03:00.0: Output Context DMA address = 0x1eb32c000
[ 4774.414742] xhci_hcd 0000:03:00.0: Internal device address = 0
[ 4774.414746] xhci_hcd 0000:03:00.0: Endpoint 0x0 ep reset callback called
[ 4774.434987] usb 3-4.2: skipped 1 descriptor after configuration
[ 4774.435494] xhci_hcd 0000:03:00.0: Waiting for status stage event
[ 4774.435530] usb 3-4.2: default language 0x0409
[ 4774.435892] xhci_hcd 0000:03:00.0: Waiting for status stage event
[ 4774.436226] xhci_hcd 0000:03:00.0: Waiting for status stage event
[ 4774.436597] xhci_hcd 0000:03:00.0: Waiting for status stage event
[ 4774.436634] usb 3-4.2: udev 23, busnum 3, minor = 278
[ 4774.436637] usb 3-4.2: New USB device found, idVendor=584e, idProduct=5342
[ 4774.436639] usb 3-4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 4774.436640] usb 3-4.2: Product: RNDIS gadget
[ 4774.436642] usb 3-4.2: Manufacturer: NuttX
[ 4774.436644] usb 3-4.2: SerialNumber: 1234
[ 4774.436865] usb 3-4.2: usb_probe_device
[ 4774.436873] usb 3-4.2: configuration #1 chosen from 1 choice
[ 4774.436910] xhci_hcd 0000:03:00.0: add ep 0x83, slot id 8, new drop flags = 0x0, new add flags = 0x80
[ 4774.437036] xhci_hcd 0000:03:00.0: add ep 0x81, slot id 8, new drop flags = 0x0, new add flags = 0x88
[ 4774.437056] xhci_hcd 0000:03:00.0: add ep 0x2, slot id 8, new drop flags = 0x0, new add flags = 0x98
[ 4774.437060] xhci_hcd 0000:03:00.0: xhci_check_bandwidth called for udev 000000005b9abb34
[ 4774.437066] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4774.437169] xhci_hcd 0000:03:00.0: Successful Endpoint Configure command
[ 4774.437173] xhci_hcd 0000:03:00.0: Endpoint 0x83 ep reset callback called
[ 4774.437176] xhci_hcd 0000:03:00.0: Endpoint 0x81 ep reset callback called
[ 4774.437177] xhci_hcd 0000:03:00.0: Endpoint 0x2 ep reset callback called
[ 4774.439980] usb 3-4.2: adding 3-4.2:1.0 (config #1, interface 0)
[ 4774.440061] rndis_host 3-4.2:1.0: usb_probe_interface
[ 4774.440064] rndis_host 3-4.2:1.0: usb_probe_interface - got id
[ 4774.440094] rndis_host 3-4.2:1.0: CDC descriptors on config
[ 4774.440095] rndis_host 3-4.2:1.0: skipping garbage
[ 4779.527193] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4779.527214] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4779.527224] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4779.527226] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4779.527228] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4779.527231] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4779.527233] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b6200 (DMA)
[ 4779.527235] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4779.527238] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 000000001af73fa9 (0x1b69b6200 dma), new cycle = 1
[ 4779.527240] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4779.527264] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4779.527282] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4779.527286] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b6200
[ 4779.527449] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4784.650199] xhci_hcd 0000:03:00.0: Cancel URB 00000000078eac48, dev 4.2, ep 0x0, starting at offset 0x1b69b6200
[ 4784.650208] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4784.650297] xhci_hcd 0000:03:00.0: Removing canceled TD starting at 0x1b69b6200 (dma).
[ 4784.650330] usb 3-4.2: kworker/1:3 timed out on ep0in len=0/1025
[ 4784.650336] rndis_host 3-4.2:1.0: rndis response error, code -110
[ 4789.769573] xhci_hcd 0000:03:00.0: Cancel URB 00000000078eac48, dev 4.2, ep 0x0, starting at offset 0x1b69b6230
[ 4789.769582] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4789.769668] xhci_hcd 0000:03:00.0: Removing canceled TD starting at 0x1b69b6230 (dma).
[ 4789.769704] usb 3-4.2: kworker/1:3 timed out on ep0in len=0/1025
[ 4789.769709] rndis_host 3-4.2:1.0: rndis response error, code -110
[ 4794.841288] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4794.841309] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4794.841321] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4794.841323] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4794.841326] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4794.841329] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4794.841332] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b6290 (DMA)
[ 4794.841333] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4794.841337] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 0000000010751fbb (0x1b69b6290 dma), new cycle = 1
[ 4794.841340] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4794.841369] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4794.841383] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4794.841386] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b6290
[ 4794.841522] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4799.921970] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4799.921990] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4799.922000] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4799.922002] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4799.922004] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4799.922006] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4799.922008] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b62c0 (DMA)
[ 4799.922010] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4799.922013] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 00000000053b82dd (0x1b69b62c0 dma), new cycle = 1
[ 4799.922015] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4799.922037] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4799.922072] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4799.922076] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b62c0
[ 4799.922252] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4805.055884] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4805.055889] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4805.055893] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4805.055894] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4805.055895] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4805.055896] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4805.055897] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b62f0 (DMA)
[ 4805.055898] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4805.055899] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 00000000fc7e419b (0x1b69b62f0 dma), new cycle = 1
[ 4805.055900] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4805.055914] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4805.055931] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4805.055933] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b62f0
[ 4805.056017] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4810.157679] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4810.157698] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4810.157707] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4810.157709] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4810.157711] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4810.157714] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4810.157716] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b6320 (DMA)
[ 4810.157717] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4810.157720] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 000000009e494531 (0x1b69b6320 dma), new cycle = 1
[ 4810.157722] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4810.157745] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4810.157777] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4810.157781] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b6320
[ 4810.158085] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4815.273722] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4815.273738] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4815.273744] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4815.273746] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4815.273748] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4815.273750] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4815.273752] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b6350 (DMA)
[ 4815.273753] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4815.273755] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 00000000c2a8a2a8 (0x1b69b6350 dma), new cycle = 1
[ 4815.273757] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4815.273774] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4815.273797] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4815.273800] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b6350
[ 4815.274589] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4820.321872] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4820.321894] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4820.321902] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4820.321904] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4820.321906] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4820.321909] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4820.321911] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b6380 (DMA)
[ 4820.321912] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4820.321916] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 000000009ef42c82 (0x1b69b6380 dma), new cycle = 1
[ 4820.321918] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4820.321940] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4820.321972] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4820.321976] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b6380
[ 4820.322286] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4825.456116] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4825.456136] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4825.456145] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4825.456148] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4825.456149] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4825.456152] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4825.456154] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b63b0 (DMA)
[ 4825.456156] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4825.456159] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 00000000f3da1c0b (0x1b69b63b0 dma), new cycle = 1
[ 4825.456161] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4825.456184] xhci_hcd 0000:03:00.0: Giveback URB 00000000078eac48, len = 0, expected = 1025, status = -71
[ 4825.456218] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4825.456223] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b63b0
[ 4825.456529] rndis_host 3-4.2:1.0: rndis response error, code -71
[ 4825.504907] rndis_host 3-4.2:1.0: rndis response timeout
[ 4825.504911] rndis_host 3-4.2:1.0: RNDIS init failed, -110
[ 4825.504954] rndis_host: probe of 3-4.2:1.0 failed with error -110
[ 4825.504976] rndis_wlan 3-4.2:1.0: usb_probe_interface
[ 4825.504980] rndis_wlan 3-4.2:1.0: usb_probe_interface - got id
[ 4825.505106] rndis_wlan 3-4.2:1.0: CDC descriptors on config
[ 4825.505108] rndis_wlan 3-4.2:1.0: skipping garbage
[ 4830.505802] xhci_hcd 0000:03:00.0: Transfer error for slot 8 ep 0 on endpoint
[ 4830.505823] xhci_hcd 0000:03:00.0: TRB error 4, halted endpoint index = 0
[ 4830.505831] xhci_hcd 0000:03:00.0: Cleaning up stalled endpoint ring
[ 4830.505834] xhci_hcd 0000:03:00.0: Finding endpoint context
[ 4830.505836] xhci_hcd 0000:03:00.0: Cycle state = 0x1
[ 4830.505839] xhci_hcd 0000:03:00.0: New dequeue segment = 00000000b30d220e (virtual)
[ 4830.505841] xhci_hcd 0000:03:00.0: New dequeue pointer = 0x1b69b63e0 (DMA)
[ 4830.505842] xhci_hcd 0000:03:00.0: Queueing new dequeue state
[ 4830.505845] xhci_hcd 0000:03:00.0: Set TR Deq Ptr cmd, new deq seg = 00000000b30d220e (0x1b69b6000 dma), new deq ptr = 00000000e3da8459 (0x1b69b63e0 dma), new cycle = 1
[ 4830.505847] xhci_hcd 0000:03:00.0: // Ding dong!
[ 4830.505869] xhci_hcd 0000:03:00.0: Giveback URB 00000000437ac163, len = 0, expected = 24, status = -71
[ 4830.505901] xhci_hcd 0000:03:00.0: Ignoring reset ep completion code of 1
[ 4830.505905] xhci_hcd 0000:03:00.0: Successful Set TR Deq Ptr cmd, deq = @1b69b63e0
[ 4830.506263] rndis_wlan 3-4.2:1.0: RNDIS init failed, -71
[ 4830.506358] rndis_wlan: probe of 3-4.2:1.0 failed with error -71
[ 4830.506407] usb 3-4.2: adding 3-4.2:1.1 (config #1, interface 1)
[ 4830.506587] hub 3-4:1.0: state 7 ports 7 chg 0000 evt 0004
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org