[jaunty] wifi disconnects sporadically (order of a few minutes)

[Alexander Jones]

Binary package hint: network-manager

This is with ath9k on AR5418 (MacBook Pro 3.1). Mac OS works fine, Intrepid worked a fair bit better (though still very difficult to connect sometimes).

This is the log after a successful connection (which itself is a pretty rare thing):

Jan 1 16:12:26 fizz ntpd[11456]: frequency initialized 0.000 PPM from /var/lib/ntp/ntp.drift
Jan 1 16:12:49 fizz NetworkManager: <info> (ath0): supplicant connection state change: 7 -> 0
Jan 1 16:12:49 fizz NetworkManager: <info> (ath0): supplicant connection state change: 0 -> 2
Jan 1 16:12:51 fizz NetworkManager: <info> (ath0): supplicant connection state change: 2 -> 3
Jan 1 16:12:56 fizz NetworkManager: <debug> [1230826376.612930] periodic_update(): Roamed from BSSID 00:80:C8:37:FD:CB (lsw) to (none) ((none))
Jan 1 16:13:01 fizz NetworkManager: <info> (ath0): supplicant connection state change: 3 -> 0
Jan 1 16:13:01 fizz NetworkManager: <info> (ath0): supplicant connection state change: 0 -> 2
Jan 1 16:13:04 fizz NetworkManager: <info> (ath0): supplicant connection state change: 2 -> 3
Jan 1 16:13:04 fizz NetworkManager: <info> (ath0): device state change: 8 -> 3
Jan 1 16:13:04 fizz NetworkManager: <info> (ath0): deactivating device (reason: 11).
Jan 1 16:13:04 fizz NetworkManager: <info> ath0: canceled DHCP transaction, dhcp client pid 11344
Jan 1 16:13:04 fizz NetworkManager: <WARN> check_one_route(): (ath0) error -34 returned from rtnl_route_del(): Sucess
Jan 1 16:13:04 fizz dnsmasq[5682]: no servers found in /etc/resolv.conf, will retry
Jan 1 16:13:04 fizz NetworkManager: <info> Activation (ath0) starting connection 'Auto lsw'

It seems the supplicant changes to state 0 often when it is failing to connect, too, as seen here:
Jan 1 16:11:13 fizz NetworkManager: <info> (ath0): supplicant connection state change: 2 -> 0
Jan 1 16:11:14 fizz NetworkManager: <info> (ath0): supplicant connection state change: 0 -> 2
Jan 1 16:11:16 fizz NetworkManager: <info> (ath0): supplicant connection state change: 2 -> 3
Jan 1 16:11:26 fizz NetworkManager: <info> (ath0): supplicant connection state change: 3 -> 0
Jan 1 16:11:26 fizz NetworkManager: <info> (ath0): supplicant connection state change: 0 -> 2
Jan 1 16:11:28 fizz NetworkManager: <info> ath0: link timed out.
Jan 1 16:11:29 fizz NetworkManager: <info> (ath0): supplicant connection state change: 2 -> 3
Jan 1 16:11:39 fizz NetworkManager: <info> (ath0): supplicant connection state change: 3 -> 0
Jan 1 16:11:39 fizz NetworkManager: <info> (ath0): supplicant connection state change: 0 -> 2
Jan 1 16:11:41 fizz NetworkManager: <info> (ath0): supplicant connection state change: 2 -> 3
Jan 1 16:11:51 fizz NetworkManager: <info> (ath0): supplicant connection state change: 3 -> 0
Jan 1 16:11:51 fizz NetworkManager: <info> (ath0): supplicant connection state change: 0 -> 2
Jan 1 16:11:53 fizz NetworkManager: <info> (ath0): supplicant connection state change: 2 -> 3
Jan 1 16:11:54 fizz NetworkManager: <info> ath0: link timed out.
Jan 1 16:12:03 fizz NetworkManager: <info> (ath0): supplicant connection state change: 3 -> 0
Jan 1 16:12:03 fizz NetworkManager: <info> (ath0): supplicant connection state change: 0 -> 2
Jan 1 16:12:06 fizz NetworkManager: <info> (ath0): supplicant connection state change: 2 -> 3
Jan 1 16:12:13 fizz NetworkManager: <info> Activation (ath0/wireless): association took too long, failing activation.

When actually connected, this happens (variations of):

Jan 1 16:15:08 fizz NetworkManager: <debug> [1230826508.680896] periodic_update(): Roamed from BSSID 00:80:C8:37:FD:CB (lsw) to (none) ((none))
Jan 1 16:15:14 fizz NetworkManager: <debug> [1230826514.682292] periodic_update(): Roamed from BSSID (none) ((none)) to 00:80:C8:37:FD:CB (lsw)
Jan 1 16:16:08 fizz NetworkManager: <debug> [1230826568.722792] periodic_update(): Roamed from BSSID 00:80:C8:37:FD:CB (lsw) to (none) ((none))
Jan 1 16:16:14 fizz NetworkManager: <debug> [1230826574.724005] periodic_update(): Roamed from BSSID (none) ((none)) to 00:80:C8:37:FD:CB (lsw)
Jan 1 16:19:08 fizz NetworkManager: <debug> [1230826748.865021] periodic_update(): Roamed from BSSID 00:80:C8:37:FD:CB (lsw) to (none) ((none))
Jan 1 16:19:14 fizz NetworkManager: <debug> [1230826754.865660] periodic_update(): Roamed from BSSID (none) ((none)) to 00:80:C8:37:FD:CB (lsw)
Jan 1 16:21:08 fizz NetworkManager: <debug> [1230826868.964543] periodic_update(): Roamed from BSSID 00:80:C8:37:FD:CB (lsw) to (none) ((none))
Jan 1 16:21:14 fizz NetworkManager: <debug> [1230826874.965942] periodic_update(): Roamed from BSSID (none) ((none)) to 00:80:C8:37:FD:CB (lsw)
Jan 1 16:23:09 fizz NetworkManager: <debug> [1230826989.064450] periodic_update(): Roamed from BSSID 00:80:C8:37:FD:CB (lsw) to (none) ((none))
Jan 1 16:23:09 fizz NetworkManager: <info> (ath0): supplicant connection state change: 7 -> 0
Jan 1 16:23:09 fizz NetworkManager: <info> (ath0): supplicant connection state change: 0 -> 2
Jan 1 16:23:11 fizz NetworkManager: <info> (ath0): supplicant connection state change: 2 -> 3
Jan 1 16:23:11 fizz NetworkManager: <info> (ath0): supplicant connection state change: 3 -> 4
Jan 1 16:23:11 fizz NetworkManager: <info> (ath0): supplicant connection state change: 4 -> 7
Jan 1 16:23:15 fizz NetworkManager: <debug> [1230826995.066890] periodic_update(): Roamed from BSSID (none) ((none)) to 00:80:C8:37:FD:CB (lsw)
Jan 1 16:25:09 fizz NetworkManager: <debug> [1230827109.173107] periodic_update(): Roamed from BSSID 00:80:C8:37:FD:CB (lsw) to (none) ((none))
Jan 1 16:25:09 fizz NetworkManager: <info> (ath0): supplicant connection state change: 7 -> 0
Jan 1 16:25:09 fizz NetworkManager: <info> (ath0): supplicant connection state change: 0 -> 2
Jan 1 16:25:11 fizz NetworkManager: <info> (ath0): supplicant connection state change: 2 -> 3
Jan 1 16:25:11 fizz NetworkManager: <info> (ath0): supplicant connection state change: 3 -> 4
Jan 1 16:25:11 fizz NetworkManager: <info> (ath0): supplicant connection state change: 4 -> 7
Jan 1 16:25:15 fizz NetworkManager: <debug> [1230827115.174356] periodic_update(): Roamed from BSSID (none) ((none)) to 00:80:C8:37:FD:CB (lsw)

The "roaming" to a null WAP worries me...

[Andrei Dziahel (develop7)]

Hi.

I'm experiencing same issues on Acer Extenza 5620Z when connected to D-Link access point. While I'm connected to Zyxel P660HTW access point, an issue is not reproduced.

What could it be?

Thanks.

[Andrei Dziahel (develop7)]

Hi. I've got some logs related to this issue. See attachment.

As we can see, first dhclient asks for leases, does not get any, goes to sleep and NM disconnects WLAN and marks this connection as invalid.

May be this issue is somehow related to dhclient?

BTW, i'm experiencing this issue when connecting to AP D-link DWL-2100AP.

UPD: I've got an workaround for this issue - I've switched to static IP and everythiing works fine.

Thanks.

[Pedro Villavicencio (pedro)]

Thank you for taking the time to report this bug and helping to make Ubuntu better. The issue that you reported is one that should be reproducible with the live environment of the Desktop CD of the development release the Karmic Koala. It would help us greatly if you could test with it so we can work on getting it fixed in the next release of Ubuntu. You can find out more about the development release at http://www.ubuntu.com/testing/ . Thanks again and we appreciate your help.

[Mikko Ohtamaa (mikko-red-innovation)]

I think there is more active bug report about the same issue(s):

https://bugs.launchpad.net/ubuntu/+source/network-manager/+bug/495981