[Regression] USB tethering does not work anymore in 2.6.29-rc2 (rndis_host, does not receive DHCP offer anymore)

[Regression] USB tethering does not work anymore in 2.6.29-rc2 (rndis_host, does not receive DHCP offer anymore)

[Gottfried Haider]

Hello,

I am using an Android phone connected over USB to connect to the
internet. Something in -rc2 broke this, as I am not getting
connections through NetworkManager anymore (it doesn't receive a
DHCPOFFER anymore and times out).

This does work on the -rc1 kernel and is 100% reproducible here (same
USB port, rebooting the phone between tries).


dmesg is about the same in both cases (the usb-storage is here as the
phone frist tries to act as a mass storage device after connect and I
have to manually activate a checkbox to switch to tethering
functionality):

[  235.150385] usb 1-3: new high speed USB device number 3 using ehci_hcd
[  235.320523] scsi2 : usb-storage 1-3:1.0
[  235.801209] usb 1-3: USB disconnect, device number 3
[  236.200390] usb 1-3: new high speed USB device number 4 using ehci_hcd
[  236.452982] usbcore: registered new interface driver cdc_ether
[  236.473241] rndis_host 1-3:1.0: usb0: register 'rndis_host' at
usb-0000:00:12.2-3, RNDIS device, 06:0f:e2:6a:61:cd
[  236.474151] usbcore: registered new interface driver rndis_host
[  236.487433] usbcore: registered new interface driver rndis_wlan
[  246.850094] usb0: no IPv6 routers present


lspci is at http://sukzessiv.net/x120e , let me know if you need any more info.

cheers,
gohai



Below the full NetworkMonitor output of the working (-rc1) case and
below the failing (-rc2) one. I noticed the different ifindex in line
two, but other than that I don't see any difference except the
obviously missing DHCPOFFER.

-- begin working (-rc1) --
NetworkManager[1958]: <info> (usb0): carrier is OFF
NetworkManager[1958]: <info> (usb0): new Ethernet device (driver:
'rndis_host' ifindex: 5)
NetworkManager[1958]: <info> (usb0): exported as
/org/freedesktop/NetworkManager/Devices/2
NetworkManager[1958]: <info> (usb0): now managed
NetworkManager[1958]: <info> (usb0): device state change: 1 -> 2 (reason 2)
NetworkManager[1958]: <info> (usb0): bringing up device.
NetworkManager[1958]: <info> (usb0): preparing device.
NetworkManager[1958]: <info> (usb0): deactivating device (reason: 2).
NetworkManager[1958]: <info> Added default wired connection 'Auto
usb0' for /sys/devices/pci0000:00/0000:00:12.2/usb1/1-3/1-3:1.0/net/usb0
NetworkManager[1958]: <info> (usb0): carrier now ON (device state 2)
NetworkManager[1958]: <info> (usb0): device state change: 2 -> 3 (reason 40)
NetworkManager[1958]:    SCPlugin-Ifupdown: devices added (path:
/sys/devices/pci0000:00/0000:00:12.2/usb1/1-3/1-3:1.0/net/usb0, iface:
usb0)
NetworkManager[1958]:    SCPlugin-Ifupdown: device added (path:
/sys/devices/pci0000:00/0000:00:12.2/usb1/1-3/1-3:1.0/net/usb0, iface:
usb0): no ifupdown configuration found.
NetworkManager[1958]: <info> Activation (usb0) starting connection 'Auto usb0'
NetworkManager[1958]: <info> (usb0): device state change: 3 -> 4 (reason 0)
NetworkManager[1958]: <info> Activation (usb0) Stage 1 of 5 (Device
Prepare) scheduled...
NetworkManager[1958]: <info> Activation (usb0) Stage 1 of 5 (Device
Prepare) started...
NetworkManager[1958]: <info> Activation (usb0) Stage 2 of 5 (Device
Configure) scheduled...
NetworkManager[1958]: <info> Activation (usb0) Stage 1 of 5 (Device
Prepare) complete.
NetworkManager[1958]: <info> Activation (usb0) Stage 2 of 5 (Device
Configure) starting...
NetworkManager[1958]: <info> (usb0): device state change: 4 -> 5 (reason 0)
NetworkManager[1958]: <info> Activation (usb0) Stage 2 of 5 (Device
Configure) successful.
NetworkManager[1958]: <info> Activation (usb0) Stage 3 of 5 (IP
Configure Start) scheduled.
NetworkManager[1958]: <info> Activation (usb0) Stage 2 of 5 (Device
Configure) complete.
NetworkManager[1958]: <info> Activation (usb0) Stage 3 of 5 (IP
Configure Start) started...
NetworkManager[1958]: <info> (usb0): device state change: 5 -> 7 (reason 0)
NetworkManager[1958]: <info> Activation (usb0) Beginning DHCPv4
transaction (timeout in 45 seconds)
NetworkManager[1958]: <info> dhclient started with pid 2030
NetworkManager[1958]: <info> Activation (usb0) Stage 3 of 5 (IP
Configure Start) complete.
Internet Systems Consortium DHCP Client 4.1.1-P1
Copyright 2004-2010 Internet Systems Consortium.
All rights reserved.
For info, please visit https://www.isc.org/software/dhcp/

NetworkManager[1958]: <info> (usb0): DHCPv4 state changed nbi -> preinit
Listening on LPF/usb0/3e:fd:8f:24:d4:25
Sending on   LPF/usb0/3e:fd:8f:24:d4:25
Sending on   Socket/fallback
DHCPDISCOVER on usb0 to 255.255.255.255 port 67 interval 3
DHCPDISCOVER on usb0 to 255.255.255.255 port 67 interval 5
DHCPOFFER of 192.168.42.47 from 192.168.42.129
DHCPREQUEST of 192.168.42.47 on usb0 to 255.255.255.255 port 67
DHCPACK of 192.168.42.47 from 192.168.42.129
NetworkManager[1958]: <info> (usb0): DHCPv4 state changed preinit -> bound
NetworkManager[1958]: <info> Activation (usb0) Stage 4 of 5 (IP4
Configure Get) scheduled...
NetworkManager[1958]: <info> Activation (usb0) Stage 4 of 5 (IP4
Configure Get) started...
NetworkManager[1958]: <info>   address 192.168.42.47
NetworkManager[1958]: <info>   prefix 24 (255.255.255.0)
NetworkManager[1958]: <info>   gateway 192.168.42.129
NetworkManager[1958]: <info>   hostname 'x120e'
NetworkManager[1958]: <info>   nameserver '192.168.42.129'
bound to 192.168.42.47 -- renewal in 1587 seconds.
NetworkManager[1958]: <info> Scheduling stage 5
NetworkManager[1958]: <info> Activation (usb0) Stage 5 of 5 (IP
Configure Commit) scheduled...
NetworkManager[1958]: <info> Done scheduling stage 5
NetworkManager[1958]: <info> Activation (usb0) Stage 4 of 5 (IP4
Configure Get) complete.
NetworkManager[1958]: <info> Activation (usb0) Stage 5 of 5 (IP
Configure Commit) started...
NetworkManager[1958]: <info> (usb0): device state change: 7 -> 8 (reason 0)
NetworkManager[1958]: <info> Policy set 'Auto usb0' (usb0) as default
for IPv4 routing and DNS.
NetworkManager[1958]: <info> Activation (usb0) successful, device activated.
NetworkManager[1958]: <info> Activation (usb0) Stage 5 of 5 (IP
Configure Commit) complete.
-- end working (-rc1) --

-- begin fail (-rc2) --
NetworkManager[2541]: <info> (usb0): carrier is OFF
NetworkManager[2541]: <info> (usb0): new Ethernet device (driver:
'rndis_host' ifindex: 6)
NetworkManager[2541]: <info> (usb0): exported as
/org/freedesktop/NetworkManager/Devices/2
NetworkManager[2541]: <info> (usb0): now managed
NetworkManager[2541]: <info> (usb0): device state change: 1 -> 2 (reason 2)
NetworkManager[2541]: <info> (usb0): bringing up device.
NetworkManager[2541]: <info> (usb0): preparing device.
NetworkManager[2541]: <info> (usb0): deactivating device (reason: 2).
NetworkManager[2541]: <info> Added default wired connection 'Auto
usb0' for /sys/devices/pci0000:00/0000:00:12.2/usb1/1-3/1-3:1.0/net/usb0
NetworkManager[2541]: <info> (usb0): carrier now ON (device state 2)
NetworkManager[2541]: <info> (usb0): device state change: 2 -> 3 (reason 40)
NetworkManager[2541]:    SCPlugin-Ifupdown: devices added (path:
/sys/devices/pci0000:00/0000:00:12.2/usb1/1-3/1-3:1.0/net/usb0, iface:
usb0)
NetworkManager[2541]:    SCPlugin-Ifupdown: device added (path:
/sys/devices/pci0000:00/0000:00:12.2/usb1/1-3/1-3:1.0/net/usb0, iface:
usb0): no ifupdown configuration found.
NetworkManager[2541]: <info> Activation (usb0) starting connection 'Auto usb0'
NetworkManager[2541]: <info> (usb0): device state change: 3 -> 4 (reason 0)
NetworkManager[2541]: <info> Activation (usb0) Stage 1 of 5 (Device
Prepare) scheduled...
NetworkManager[2541]: <info> Activation (usb0) Stage 1 of 5 (Device
Prepare) started...
NetworkManager[2541]: <info> Activation (usb0) Stage 2 of 5 (Device
Configure) scheduled...
NetworkManager[2541]: <info> Activation (usb0) Stage 1 of 5 (Device
Prepare) complete.
NetworkManager[2541]: <info> Activation (usb0) Stage 2 of 5 (Device
Configure) starting...
NetworkManager[2541]: <info> (usb0): device state change: 4 -> 5 (reason 0)
NetworkManager[2541]: <info> Activation (usb0) Stage 2 of 5 (Device
Configure) successful.
NetworkManager[2541]: <info> Activation (usb0) Stage 3 of 5 (IP
Configure Start) scheduled.
NetworkManager[2541]: <info> Activation (usb0) Stage 2 of 5 (Device
Configure) complete.
NetworkManager[2541]: <info> Activation (usb0) Stage 3 of 5 (IP
Configure Start) started...
NetworkManager[2541]: <info> (usb0): device state change: 5 -> 7 (reason 0)
NetworkManager[2541]: <info> Activation (usb0) Beginning DHCPv4
transaction (timeout in 45 seconds)
NetworkManager[2541]: <info> dhclient started with pid 2609
NetworkManager[2541]: <info> Activation (usb0) Stage 3 of 5 (IP
Configure Start) complete.
Internet Systems Consortium DHCP Client 4.1.1-P1
Copyright 2004-2010 Internet Systems Consortium.
All rights reserved.
For info, please visit https://www.isc.org/software/dhcp/

NetworkManager[2541]: <info> (usb0): DHCPv4 state changed nbi -> preinit
Listening on LPF/usb0/06:eb:ae:9f:5d:5d
Sending on   LPF/usb0/06:eb:ae:9f:5d:5d
Sending on   Socket/fallback
DHCPDISCOVER on usb0 to 255.255.255.255 port 67 interval 3
DHCPDISCOVER on usb0 to 255.255.255.255 port 67 interval 4
DHCPDISCOVER on usb0 to 255.255.255.255 port 67 interval 5
DHCPDISCOVER on usb0 to 255.255.255.255 port 67 interval 13
DHCPDISCOVER on usb0 to 255.255.255.255 port 67 interval 18
DHCPDISCOVER on usb0 to 255.255.255.255 port 67 interval 14
NetworkManager[2541]: <warn> (usb0): DHCPv4 request timed out.
NetworkManager[2541]: <info> (usb0): canceled DHCP transaction, DHCP
client pid 2609
NetworkManager[2541]: <info> Activation (usb0) Stage 4 of 5 (IP4
Configure Timeout) scheduled...
NetworkManager[2541]: <info> Activation (usb0) Stage 4 of 5 (IP4
Configure Timeout) started...
NetworkManager[2541]: <info> Activation (usb0) Stage 5 of 5 (IP
Configure Commit) scheduled...
NetworkManager[2541]: <info> Activation (usb0) Stage 4 of 5 (IP4
Configure Timeout) complete.
NetworkManager[2541]: <info> Activation (usb0) Stage 5 of 5 (IP
Configure Commit) started...
NetworkManager[2541]: <info> Activation (usb0) Stage 5 of 5 (IP
Configure Commit) failed (no IP configuration found)
NetworkManager[2541]: <info> (usb0): device state change: 7 -> 9 (reason 5)
NetworkManager[2541]: <info> Marking connection 'Auto usb0' invalid.
NetworkManager[2541]: <warn> Activation (usb0) failed.
NetworkManager[2541]: <info> Activation (usb0) Stage 5 of 5 (IP
Configure Commit) complete.
NetworkManager[2541]: <info> (usb0): device state change: 9 -> 3 (reason 0)
NetworkManager[2541]: <info> (usb0): deactivating device (reason: 0).
-- end fail (-rc2) --

Re: [Regression] USB tethering does not work anymore in 2.6.29-rc2 (rndis_host, does not receive DHCP offer anymore)

[Greg KH]

On Thu, Apr 07, 2011 at 04:11:27AM +0200, Gottfried Haider wrote:
> Hello,
> 
> I am using an Android phone connected over USB to connect to the
> internet. Something in -rc2 broke this, as I am not getting
> connections through NetworkManager anymore (it doesn't receive a
> DHCPOFFER anymore and times out).
> 
> This does work on the -rc1 kernel and is 100% reproducible here (same
> USB port, rebooting the phone between tries).

Any chance you can run 'git bisect' to narrow down the problem to the
offending change?

thanks,

greg k-h

Re: [Regression] USB tethering does not work anymore in 2.6.29-rc2 (rndis_host, does not receive DHCP offer anymore)

[Greg KH]

On Thu, Apr 07, 2011 at 09:39:48AM -0700, Greg KH wrote:
> On Thu, Apr 07, 2011 at 04:11:27AM +0200, Gottfried Haider wrote:
> > Hello,
> > 
> > I am using an Android phone connected over USB to connect to the
> > internet. Something in -rc2 broke this, as I am not getting
> > connections through NetworkManager anymore (it doesn't receive a
> > DHCPOFFER anymore and times out).
> > 
> > This does work on the -rc1 kernel and is 100% reproducible here (same
> > USB port, rebooting the phone between tries).
> 
> Any chance you can run 'git bisect' to narrow down the problem to the
> offending change?

I just tested this myself and can confirm it doesn't work, but I will
not have the time to run 'git bisect' until next week as I'm on the road
:(

thanks,

greg k-h

Re: [Regression] USB tethering does not work anymore in 2.6.29-rc2 (rndis_host, does not receive DHCP offer anymore)

[Gottfried Haider]

>> This does work on the -rc1 kernel and is 100% reproducible here (same
>> USB port, rebooting the phone between tries).
>
> Any chance you can run 'git bisect' to narrow down the problem to the
> offending change?

Unfortunately I only have this x120e netbook-type machine available
for testing and building at the moment, so it would probably take me a
long time.

Gottfried

Re: [Regression] USB tethering does not work anymore in 2.6.29-rc2 (rndis_host, does not receive DHCP offer anymore)

[huajun li]

2011/4/8 Gottfried Haider <gottfried.haider@gmail.com>:
>>> This does work on the -rc1 kernel and is 100% reproducible here (same
>>> USB port, rebooting the phone between tries).
>>
>> Any chance you can run 'git bisect' to narrow down the problem to the
>> offending change?
>
> Unfortunately I only have this x120e netbook-type machine available
> for testing and building at the moment, so it would probably take me a
> long time.
>
> Gottfried
> --
> To unsubscribe from this list: send the line "unsubscribe linux-usb" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>

Hi,
   I found the new added mask code 'FLAG_POINTTOPOINT' overlapped
'FLAG_MULTI_PACKET' in    include/linux/usb/usbnet.h, this maybe
caused logic issue in rx_process(). I create a patch for this, but
have no such a device to test it, could you have a try? thanks.

Thanks,
--huajun


[PATCH]    Clean up mask code overlaps in driver_info of usbnet

Signed-off-by:  Huajun Li <huajun.li.lee@gmail.com>
---
 include/linux/usb/usbnet.h |    4 ++--
 1 files changed, 2 insertions(+), 2 deletions(-)

diff --git a/include/linux/usb/usbnet.h b/include/linux/usb/usbnet.h
index 3c7329b..0e18550 100644
--- a/include/linux/usb/usbnet.h
+++ b/include/linux/usb/usbnet.h
@@ -103,8 +103,8 @@ struct driver_info {
  * Indicates to usbnet, that USB driver accumulates multiple IP packets.
  * Affects statistic (counters) and short packet handling.
  */
-#define FLAG_MULTI_PACKET	0x1000
-#define FLAG_RX_ASSEMBLE	0x2000	/* rx packets may span >1 frames */
+#define FLAG_MULTI_PACKET	0x2000
+#define FLAG_RX_ASSEMBLE	0x4000	/* rx packets may span >1 frames */

 	/* init device ... can sleep, or cause probe() failure */
 	int	(*bind)(struct usbnet *, struct usb_interface *);
-- 
1.7.4.1

Re: [Regression] USB tethering does not work anymore in 2.6.29-rc2 (rndis_host, does not receive DHCP offer anymore)

[Gottfried Haider]

>   I found the new added mask code 'FLAG_POINTTOPOINT' overlapped
> 'FLAG_MULTI_PACKET' in    include/linux/usb/usbnet.h, this maybe
> caused logic issue in rx_process(). I create a patch for this, but
> have no such a device to test it, could you have a try? thanks.

Will try the patch tomorrow morning and report back.

Gottfried


> [PATCH]    Clean up mask code overlaps in driver_info of usbnet
>
> Signed-off-by:  Huajun Li <huajun.li.lee@gmail.com>
> ---
>  include/linux/usb/usbnet.h |    4 ++--
>  1 files changed, 2 insertions(+), 2 deletions(-)
>
> diff --git a/include/linux/usb/usbnet.h b/include/linux/usb/usbnet.h
> index 3c7329b..0e18550 100644
> --- a/include/linux/usb/usbnet.h
> +++ b/include/linux/usb/usbnet.h
> @@ -103,8 +103,8 @@ struct driver_info {
>  * Indicates to usbnet, that USB driver accumulates multiple IP packets.
>  * Affects statistic (counters) and short packet handling.
>  */
> -#define FLAG_MULTI_PACKET      0x1000
> -#define FLAG_RX_ASSEMBLE       0x2000  /* rx packets may span >1 frames */
> +#define FLAG_MULTI_PACKET      0x2000
> +#define FLAG_RX_ASSEMBLE       0x4000  /* rx packets may span >1 frames */
>
>        /* init device ... can sleep, or cause probe() failure */
>        int     (*bind)(struct usbnet *, struct usb_interface *);

Re: [Regression] USB tethering does not work anymore in 2.6.29-rc2 (rndis_host, does not receive DHCP offer anymore)

[Gottfried Haider]

> Hi,
>   I found the new added mask code 'FLAG_POINTTOPOINT' overlapped
> 'FLAG_MULTI_PACKET' in    include/linux/usb/usbnet.h, this maybe
> caused logic issue in rx_process(). I create a patch for this, but
> have no such a device to test it, could you have a try? thanks.

That patch fixes it, thanks!

Gottfried