701768 – [ath9k] Network not accessible after associating with AP

Bug 701768 - [ath9k] Network not accessible after associating with AP

Summary: [ath9k] Network not accessible after associating with AP

Keywords:
Status:	CLOSED INSUFFICIENT_DATA
Alias:	None
Product:	Fedora
Classification:	Fedora
Component:	kernel
Sub Component:
Version:	15
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	unspecified
Target Milestone:	---
Assignee:	Kernel Maintainer List
QA Contact:	Fedora Extras Quality Assurance
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2011-05-03 19:40 UTC by Bastien Nocera
Modified:	2012-06-04 19:09 UTC (History)
CC List:	9 users (show)
Fixed In Version:
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:	2012-06-04 19:09:09 UTC
Type:	---
Embargoed:
Dependent Products:

Attachments	(Terms of Use)

Description Bastien Nocera 2011-05-03 19:40:57 UTC

Tested with:

$ uname -r
2.6.39-0.r5.git0.0.fc16.x86_64

and 2.6.38.5-22.fc15.x86_64.

$  nm-tool

NetworkManager Tool

State: connected (global)

- Device: wlan0  [Auto idoru] --------------------------------------------------
  Type:              802.11 WiFi
  Driver:            ath9k
  State:             connected
  Default:           yes
  HW Address:        48:5D:60:22:9F:6A

  Capabilities:
    Speed:           65 Mb/s

  Wireless Properties
    WEP Encryption:  yes
    WPA Encryption:  yes
    WPA2 Encryption: yes

  Wireless Access Points (* = current AP)
    Intimidating:    Infra, 1C:BD:B9:8F:87:8C, Freq 2462 MHz, Rate 54 Mb/s, Strength 15 WPA WPA2
    hamster70:       Infra, 00:1E:2A:7D:82:F1, Freq 2412 MHz, Rate 54 Mb/s, Strength 19 WPA WPA2
    SKY62989:        Infra, 00:26:91:2A:F6:0E, Freq 2437 MHz, Rate 54 Mb/s, Strength 25 WPA
    Nightshard:      Infra, 00:14:6C:9D:4E:44, Freq 2462 MHz, Rate 54 Mb/s, Strength 19 WPA
    O2wirelessFAB733:Infra, 00:24:17:FA:B7:33, Freq 2437 MHz, Rate 54 Mb/s, Strength 15 WPA WPA2
    virginmedia8301376: Infra, C0:3F:0E:C2:DD:26, Freq 2412 MHz, Rate 54 Mb/s, Strength 15 WPA WPA2
    O2wireless90E969:Infra, 00:26:44:90:E9:69, Freq 2462 MHz, Rate 54 Mb/s, Strength 17 WPA WPA2
    *idoru:          Infra, 1C:AF:F7:45:94:CE, Freq 2457 MHz, Rate 54 Mb/s, Strength 100 WPA WPA2
    bn4:             Infra, 00:26:F2:02:ED:90, Freq 2462 MHz, Rate 54 Mb/s, Strength 12 WPA2
    virginmedia5380846: Infra, C0:3F:0E:BF:20:04, Freq 2437 MHz, Rate 54 Mb/s, Strength 19 WPA WPA2
    bn4:             Infra, 00:1B:2F:6A:D1:1E, Freq 2437 MHz, Rate 54 Mb/s, Strength 27 WPA2
    O2wirelessDE5F2F:Infra, 00:24:17:DE:5F:2F, Freq 2437 MHz, Rate 54 Mb/s, Strength 10 WPA WPA2
    TALKTALK-685C04: Infra, 00:E0:4D:68:5C:06, Freq 2412 MHz, Rate 54 Mb/s, Strength 30 WPA WPA2
    virginmedia2995148: Infra, 30:46:9A:7E:92:57, Freq 2437 MHz, Rate 54 Mb/s, Strength 15 WPA WPA2

  IPv4 Settings:
    Address:         192.168.1.115
    Prefix:          24 (255.255.255.0)
    Gateway:         192.168.1.254

    DNS:             192.168.1.254

# modprobe ath9k nohwcrypt=1

/var/log/messages output during modprobe and subsequent association:
May  3 19:10:08 wetab kernel: [ 3511.596779] ath9k 0000:01:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
May  3 19:10:08 wetab kernel: [ 3511.734938] ieee80211 phy5: Atheros AR9285 Rev:2 mem=0xffffc90004a20000, irq=16
May  3 19:10:08 wetab NetworkManager[657]: <info> (wlan0): driver supports SSID scans (scan_capa 0x01).
May  3 19:10:08 wetab NetworkManager[657]: <info> (wlan0): new 802.11 WiFi device (driver: 'ath9k' ifindex: 7)
May  3 19:10:08 wetab NetworkManager[657]: <info> (wlan0): exported as /org/freedesktop/NetworkManager/Devices/5
May  3 19:10:08 wetab NetworkManager[657]: <info> (wlan0): now managed
May  3 19:10:08 wetab NetworkManager[657]: <info> (wlan0): device state change: 10 -> 20 (reason 2)
May  3 19:10:08 wetab NetworkManager[657]: <info> (wlan0): bringing up device.
May  3 19:10:08 wetab kernel: [ 3512.073297] ADDRCONF(NETDEV_UP): wlan0: link is not ready
May  3 19:10:08 wetab NetworkManager[657]: <info> (wlan0): preparing device.
May  3 19:10:08 wetab NetworkManager[657]: <info> (wlan0): deactivating device (reason: 2).
May  3 19:10:08 wetab NetworkManager[657]: <info> found WiFi radio killswitch rfkill6 (at /sys/devices/pci0000:00/0000:00:1c.0/0000:01:00.0/ieee80211/phy5/rfkill6) (driver (unknown))
May  3 19:10:08 wetab NetworkManager[657]: <info> (wlan0): supplicant interface state: starting -> ready
May  3 19:10:08 wetab NetworkManager[657]: <info> (wlan0): device state change: 20 -> 30 (reason 42)
May  3 19:10:08 wetab NetworkManager[657]: <info> (wlan0): supplicant interface state: ready -> inactive
May  3 19:10:10 wetab NetworkManager[657]: <info> Activation (wlan0) starting connection 'Auto idoru'
May  3 19:10:10 wetab NetworkManager[657]: <info> (wlan0): device state change: 30 -> 40 (reason 0)
May  3 19:10:10 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
May  3 19:10:10 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
May  3 19:10:10 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
May  3 19:10:10 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
May  3 19:10:10 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
May  3 19:10:10 wetab NetworkManager[657]: <info> (wlan0): device state change: 40 -> 50 (reason 0)
May  3 19:10:10 wetab NetworkManager[657]: <info> Activation (wlan0/wireless): connection 'Auto idoru' has security, and secrets exist.  No new secrets needed.
May  3 19:10:10 wetab NetworkManager[657]: <info> Config: added 'ssid' value 'idoru'
May  3 19:10:10 wetab NetworkManager[657]: <info> Config: added 'scan_ssid' value '1'
May  3 19:10:10 wetab NetworkManager[657]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
May  3 19:10:10 wetab NetworkManager[657]: <info> Config: added 'psk' value '<omitted>'
May  3 19:10:10 wetab NetworkManager[657]: <info> Config: added 'proto' value 'WPA RSN'
May  3 19:10:10 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
May  3 19:10:10 wetab NetworkManager[657]: <info> Config: set interface ap_scan to 1
May  3 19:10:10 wetab NetworkManager[657]: <info> (wlan0): supplicant interface state: inactive -> scanning
May  3 19:10:12 wetab NetworkManager[657]: <info> (wlan0): supplicant interface state: scanning -> authenticating
May  3 19:10:12 wetab NetworkManager[657]: <info> (wlan0): supplicant interface state: authenticating -> associating
May  3 19:10:12 wetab kernel: [ 3515.643118] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
May  3 19:10:12 wetab NetworkManager[657]: <info> (wlan0): supplicant interface state: associating -> associated
May  3 19:10:12 wetab NetworkManager[657]: <info> (wlan0): supplicant interface state: associated -> 4-way handshake
May  3 19:10:12 wetab NetworkManager[657]: <info> (wlan0): supplicant interface state: 4-way handshake -> completed
May  3 19:10:12 wetab NetworkManager[657]: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network 'idoru'.
May  3 19:10:12 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.
May  3 19:10:12 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...
May  3 19:10:12 wetab NetworkManager[657]: <info> (wlan0): device state change: 50 -> 70 (reason 0)
May  3 19:10:12 wetab NetworkManager[657]: <info> Activation (wlan0) Beginning DHCPv4 transaction (timeout in 45 seconds)
May  3 19:10:12 wetab NetworkManager[657]: <info> dhclient started with pid 4060
May  3 19:10:12 wetab NetworkManager[657]: <info> Activation (wlan0) Beginning IP6 addrconf.
May  3 19:10:12 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.
May  3 19:10:12 wetab dhclient[4060]: Internet Systems Consortium DHCP Client 4.2.1-P1
May  3 19:10:12 wetab dhclient[4060]: Copyright 2004-2011 Internet Systems Consortium.
May  3 19:10:12 wetab dhclient[4060]: All rights reserved.
May  3 19:10:12 wetab dhclient[4060]: For info, please visit https://www.isc.org/software/dhcp/
May  3 19:10:12 wetab dhclient[4060]: 
May  3 19:10:12 wetab dhclient[4060]: Listening on LPF/wlan0/48:5d:60:22:9f:6a
May  3 19:10:12 wetab dhclient[4060]: Sending on   LPF/wlan0/48:5d:60:22:9f:6a
May  3 19:10:12 wetab dhclient[4060]: Sending on   Socket/fallback
May  3 19:10:12 wetab NetworkManager[657]: <info> (wlan0): DHCPv4 state changed nbi -> preinit
May  3 19:10:12 wetab dhclient[4060]: DHCPREQUEST on wlan0 to 255.255.255.255 port 67
May  3 19:10:12 wetab dhclient[4060]: DHCPACK from 192.168.1.254
May  3 19:10:13 wetab dhclient[4060]: bound to 192.168.1.115 -- renewal in 42590 seconds.
May  3 19:10:13 wetab NetworkManager[657]: <info> (wlan0): DHCPv4 state changed preinit -> reboot
May  3 19:10:13 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) scheduled...
May  3 19:10:13 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) started...
May  3 19:10:13 wetab NetworkManager[657]: <info>   address 192.168.1.115
May  3 19:10:13 wetab NetworkManager[657]: <info>   prefix 24 (255.255.255.0)
May  3 19:10:13 wetab NetworkManager[657]: <info>   gateway 192.168.1.254
May  3 19:10:13 wetab NetworkManager[657]: <info>   nameserver '192.168.1.254'
May  3 19:10:13 wetab NetworkManager[657]: <info>   domain name 'config'
May  3 19:10:13 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) complete.
May  3 19:10:15 wetab ntpd[1742]: Listen normally on 18 wlan0 fe80::4a5d:60ff:fe22:9f6a UDP 123
May  3 19:10:15 wetab ntpd[1742]: peers refreshed
May  3 19:10:17 wetab ntpd_intres[1797]: host name not found: 0.fedora.pool.ntp.org
May  3 19:10:17 wetab ntpd_intres[1797]: host name not found: 1.fedora.pool.ntp.org
May  3 19:10:17 wetab ntpd_intres[1797]: host name not found: 2.fedora.pool.ntp.org
May  3 19:10:17 wetab ntpd_intres[1797]: host name not found: 3.fedora.pool.ntp.org
May  3 19:10:32 wetab NetworkManager[657]: <info> (wlan0): IP6 addrconf timed out or failed.
May  3 19:10:32 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 4 of 5 (IP6 Configure Timeout) scheduled...
May  3 19:10:32 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 4 of 5 (IP6 Configure Timeout) started...
May  3 19:10:32 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) scheduled...
May  3 19:10:32 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 4 of 5 (IP6 Configure Timeout) complete.
May  3 19:10:32 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started...
May  3 19:10:33 wetab NetworkManager[657]: <info> (wlan0): device state change: 70 -> 100 (reason 0)
May  3 19:10:33 wetab ntpd[1742]: Listen normally on 19 wlan0 192.168.1.115 UDP 123
May  3 19:10:33 wetab ntpd[1742]: peers refreshed
May  3 19:10:33 wetab NetworkManager[657]: <info> Policy set 'Auto idoru' (wlan0) as default for IPv4 routing and DNS.
May  3 19:10:33 wetab NetworkManager[657]: <info> Activation (wlan0) successful, device activated.
May  3 19:10:33 wetab dbus: [system] Activating service name='org.freedesktop.nm_dispatcher' argv0='/lib64/dbus-1/dbus-daemon-launch-helper'
May  3 19:10:33 wetab NetworkManager[657]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complete.
May  3 19:10:34 wetab dbus: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
May  3 19:10:53 wetab kernel: [ 3556.555867] keyboard: can't emulate rawmode for keycode 240
May  3 19:10:53 wetab kernel: [ 3556.556292] keyboard: can't emulate rawmode for keycode 240
May  3 19:10:55 wetab ntpd_intres[1797]: host name not found: 0.fedora.pool.ntp.org

iwevent output during same:
iwevent 
Waiting for Wireless Events from interfaces...
19:10:10.696103   wlan0    Scan request completed
19:10:11.996636   wlan0    Scan request completed
19:10:12.108871   wlan0    Association Response IEs:010882848B961224486CDD180050F2020101000003A4000027A4000042435E0062322F002D1AEE1117FFFF0000010000000000000000000000000C000000000
19:10:12.109538   wlan0    New Access Point/Cell address:1C:AF:F7:45:94:CE
19:11:01.622957   wlan0    Scan request completed
19:11:41.476668   wlan0    Scan request completed

dmesg output during same:
[ 3725.712737] cfg80211: Regulatory domain changed to country: GB
[ 3725.712749] cfg80211:     (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[ 3725.712762] cfg80211:     (2402000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[ 3725.712773] cfg80211:     (5170000 KHz - 5250000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[ 3725.712784] cfg80211:     (5250000 KHz - 5330000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[ 3725.712794] cfg80211:     (5490000 KHz - 5710000 KHz @ 40000 KHz), (N/A, 2700 mBm)
[ 3725.713100] cfg80211: Calling CRDA for country: DE
[ 3725.793726] cfg80211: Regulatory domain changed to country: DE
[ 3725.793737] cfg80211:     (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[ 3725.793747] cfg80211:     (2400000 KHz - 2483500 KHz @ 40000 KHz), (N/A, 2000 mBm)
[ 3725.793757] cfg80211:     (5150000 KHz - 5250000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[ 3725.793766] cfg80211:     (5250000 KHz - 5350000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[ 3725.793775] cfg80211:     (5470000 KHz - 5725000 KHz @ 40000 KHz), (N/A, 2698 mBm)
[ 3725.794142] cfg80211: Calling CRDA to update world regulatory domain
[ 3725.925599] cfg80211: World regulatory domain updated:
[ 3725.925610] cfg80211:     (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[ 3725.925621] cfg80211:     (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[ 3725.925631] cfg80211:     (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[ 3725.925641] cfg80211:     (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[ 3725.925651] cfg80211:     (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[ 3725.925660] cfg80211:     (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[ 3725.926241] cfg80211: Calling CRDA for country: EU

Ping doesn't work after association:
$ ping 192.168.1.1
PING 192.168.1.1 (192.168.1.1) 56(84) bytes of data.
^C
--- 192.168.1.1 ping statistics ---
7 packets transmitted, 0 received, 100% packet loss, time 6000ms

# rmmod ath9k

Plug in Belkin 54g USB device (rt73usb), ping working, and network available.

The same problem occurs with a current F15 kernel, but worked correctly when the machine was installed using F15 alpha.

Comment 1 Stanislaw Gruszka 2011-05-10 14:19:25 UTC

We have currently some ath9k regressions on 2.6.38 and 2.6.39, I think there are patches available, but I'm not tracking them. Perhaps John or Luis could help here.

Similar bugs:
https://bugzilla.redhat.com/show_bug.cgi?id=700973
https://bugzilla.redhat.com/show_bug.cgi?id=700362
https://bugzilla.redhat.com/show_bug.cgi?id=702722

Possible workarounds:
echo "options ath9k nohwcrypt=1" >> /etc/modprobe.d/ath9k.conf
iwconfig wlan0 power off

Comment 2 Bastien Nocera 2011-05-10 14:29:53 UTC

(In reply to comment #1)
> We have currently some ath9k regressions on 2.6.38 and 2.6.39, I think there
> are patches available, but I'm not tracking them. Perhaps John or Luis could
> help here.
> 
> Similar bugs:
> https://bugzilla.redhat.com/show_bug.cgi?id=700973
> https://bugzilla.redhat.com/show_bug.cgi?id=700362
> https://bugzilla.redhat.com/show_bug.cgi?id=702722
> 
> Possible workarounds:
> echo "options ath9k nohwcrypt=1" >> /etc/modprobe.d/ath9k.conf

Nope, see comment 0.

> iwconfig wlan0 power off

Didn't try that.

It seems that the card works after resuming from suspend, but I haven't chased this more.

Comment 3 Bastien Nocera 2011-05-19 14:23:31 UTC

(In reply to comment #2)
> (In reply to comment #1)
> > We have currently some ath9k regressions on 2.6.38 and 2.6.39, I think there
> > are patches available, but I'm not tracking them. Perhaps John or Luis could
> > help here.
> > 
> > Similar bugs:
> > https://bugzilla.redhat.com/show_bug.cgi?id=700973
> > https://bugzilla.redhat.com/show_bug.cgi?id=700362
> > https://bugzilla.redhat.com/show_bug.cgi?id=702722
<snip>
> > iwconfig wlan0 power off
> 
> Didn't try that.
> 
> It seems that the card works after resuming from suspend, but I haven't chased
> this more.

Doesn't work either. I also didn't manage to make it work through suspend/resume cycles.

Comment 4 Bastien Nocera 2011-05-27 15:40:23 UTC

As discussed on the list:
http://thread.gmane.org/gmane.linux.drivers.ath9k.devel/6261/focus=6301

The problem doesn't appear when using 20MHz-wide channels, just 40MHz.

Comment 5 Stanislaw Gruszka 2011-06-09 09:13:06 UTC

Bastien, please show "iw list" command output.

Note You need to log in before you can comment on or make changes to this bug.