Bug 832980

Summary:

Can't connect to one WIFI after update to 3.4.x, others work fine.

Product:

[Fedora] Fedora

Reporter:

asdfx <asdfx1337>

Component:

kernel

Assignee:

Stanislaw Gruszka <sgruszka>

Status:

CLOSED WONTFIX

QA Contact:

Fedora Extras Quality Assurance <extras-qa>

Severity:

unspecified

Docs Contact:

Priority:

unspecified

Version:

CC:

gansalmon, itamar, jonathan, kernel-maint, linville, madhu.chinakonda, steve8988

Target Milestone:

---

Target Release:

---

Hardware:

x86_64

OS:

Linux

Whiteboard:

Fixed In Version:

Doc Type:

Bug Fix

Doc Text:

Story Points:

---

Clone Of:

Environment:

Last Closed:

2013-03-12 17:21:25 UTC

Type:

Bug

Regression:

---

Mount Type:

---

Documentation:

---

CRM:

Verified Versions:

Category:

---

oVirt Team:

---

RHEL 7.3 requirements from Atomic Host:

Cloudforms Team:

---

Target Upstream Version:

Embargoed:

Attachments:

Description	Flags
Ralink 2870, kernel 3.4.2	none
Comment	none

Description asdfx 2012-06-18 10:12:06 UTC

Description of problem:

I can't connect to a WPA2 secured wifi with kernel 3.4.0 and 3.4.2 - connecting to this wifi works fine with 3.3.7 though.
With 3.4.x kernels I can still connect to a wifi, also secured through WPA2, which is a bit closer and another with WEP.

The non-working wifi has WPS enabled, the two working ones don't.

In dmesg I see "corrupted beacon" messages and my kde networkmanager keeps asking me for the key while trying to connect with either 3.4.0 or 3.4.2. Rebooting into 3.3.7 gets it working again.

I'm running Fedora 17, this is a rt2860usb device.

Comment 1 asdfx 2012-06-18 10:38:26 UTC

And here we have dmesg, running 3.4.x (the device is wlan1):
[    9.350201] ADDRCONF(NETDEV_UP): wlan0: link is not ready
[    9.471059] RPC: Registered named UNIX socket transport module.
[    9.471068] RPC: Registered udp transport module.
[    9.471070] RPC: Registered tcp transport module.
[    9.471073] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    9.610700] r8169 0000:04:00.0: p33p1: link down
[    9.610792] r8169 0000:04:00.0: p33p1: link down
[    9.612674] ADDRCONF(NETDEV_UP): p33p1: link is not ready
[   10.693746] ADDRCONF(NETDEV_UP): wlan1: link is not ready
[   11.219878] r8169 0000:04:00.0: p33p1: link up
[   11.221910] ADDRCONF(NETDEV_CHANGE): p33p1: link becomes ready
[   12.827327] wlan0: authenticate with 00:14:6c:a0:0b:70
[   12.834216] wlan0: send auth to 00:14:6c:a0:0b:70 (try 1/3)
[   12.839562] wlan0: authenticated
[   12.847582] wlan0: associate with 00:14:6c:a0:0b:70 (try 1/3)
[   12.853206] wlan0: RX AssocResp from 00:14:6c:a0:0b:70 (capab=0x431 status=0 aid=1)
[   12.853219] wlan0: associated
[   12.856418] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   23.307566] wlan0: no IPv6 routers present
[   88.330177] SELinux: initialized (dev proc, type proc), uses genfs_contexts
[  116.208395] wlan1: authenticate with MA:CA:DD:RE:SS
[  116.305924] wlan1: send auth to MA:CA:DD:RE:SS (try 1/3)
[  116.307462] wlan1: authenticated
[  116.361207] wlan1: associate with MA:CA:DD:RE:SS (try 1/3)
[  116.379117] wlan1: RX AssocResp from MA:CA:DD:RE:SS (capab=0x411 status=0 aid=1)
[  116.379126] wlan1: associated
[  116.456176] ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[  116.456325] cfg80211: Calling CRDA for country: DE
[  116.473561] ath: regdomain 0x8114 updated by CountryIE
[  116.473568] ath: EEPROM regdomain: 0x8114
[  116.473571] ath: EEPROM indicates we should expect a country code
[  116.473574] ath: doing EEPROM country->regdmn map search
[  116.473577] ath: country maps to regdmn code: 0x37
[  116.473580] ath: Country alpha2 being used: DE
[  116.473583] ath: Regpair used: 0x37
[  116.473709] cfg80211: Regulatory domain changed to country: DE
[  116.473712] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[  116.473717] cfg80211:   (2400000 KHz - 2483500 KHz @ 40000 KHz), (N/A, 2000 mBm)
[  116.473721] cfg80211:   (5150000 KHz - 5250000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[  116.473724] cfg80211:   (5250000 KHz - 5350000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[  116.473728] cfg80211:   (5470000 KHz - 5725000 KHz @ 40000 KHz), (N/A, 2698 mBm)
[  122.677691] wlan1: deauthenticated from MA:CA:DD:RE:SS (Reason: 15)
[  124.357883] wlan1: authenticate with MA:CA:DD:RE:SS
[  124.443791] wlan1: send auth to MA:CA:DD:RE:SS (try 1/3)
[  124.445280] wlan1: authenticated
[  124.502792] wlan1: associating with AP with corrupt beacon
[  124.503323] wlan1: associate with MA:CA:DD:RE:SS (try 1/3)
[  124.529043] wlan1: RX AssocResp from MA:CA:DD:RE:SS (capab=0x411 status=0 aid=1)
[  124.529057] wlan1: associated
[  130.763834] wlan1: deauthenticated from MA:CA:DD:RE:SS (Reason: 15)
[  132.431078] wlan1: authenticate with MA:CA:DD:RE:SS
[  132.523707] wlan1: send auth to MA:CA:DD:RE:SS (try 1/3)
[  132.525252] wlan1: authenticated
[  132.580429] wlan1: associating with AP with corrupt beacon
[  132.581460] wlan1: associate with MA:CA:DD:RE:SS (try 1/3)
[  132.601466] wlan1: RX AssocResp from MA:CA:DD:RE:SS (capab=0x411 status=0 aid=1)
[  132.601480] wlan1: associated
[  138.809989] wlan1: deauthenticated from MA:CA:DD:RE:SS (Reason: 15)


and /var/log/messages (again, look for wlan1):

Jun 19 14:19:29 comp kernel: [   10.693746] ADDRCONF(NETDEV_UP): wlan1: link is not ready
Jun 19 14:19:29 comp NetworkManager[598]: <info> (wlan1): preparing device.
Jun 19 14:19:29 comp NetworkManager[598]: <info> (wlan1): deactivating device (reason 'managed') [2]
Jun 19 14:19:29 comp NetworkManager[598]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
Jun 19 14:19:29 comp NetworkManager[598]: <warn> /sys/devices/virtual/net/lo: couldn't determine device driver; ignoring...
Jun 19 14:19:29 comp NetworkManager[598]: <info> modem-manager is now available
Jun 19 14:19:29 comp NetworkManager[598]: <info> wpa_supplicant started
Jun 19 14:19:29 comp NetworkManager[598]: <info> (wlan0) supports 4 scan SSIDs
Jun 19 14:19:29 comp NetworkManager[598]: <info> (wlan0): supplicant interface state: starting -> ready
Jun 19 14:19:29 comp NetworkManager[598]: <info> (wlan0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
Jun 19 14:19:29 comp NetworkManager[598]: <warn> Trying to remove a non-existant call id.
Jun 19 14:19:29 comp NetworkManager[598]: <info> (wlan1) supports 4 scan SSIDs
Jun 19 14:19:29 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: starting -> ready
Jun 19 14:19:29 comp NetworkManager[598]: <info> (wlan1): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
Jun 19 14:19:29 comp NetworkManager[598]: <warn> Trying to remove a non-existant call id.
Jun 19 14:19:29 comp NetworkManager[598]: <info> (wlan0): supplicant interface state: ready -> inactive
Jun 19 14:19:29 comp NetworkManager[598]: <info> (wlan0) supports 4 scan SSIDs
Jun 19 14:19:29 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: ready -> inactive
Jun 19 14:19:29 comp NetworkManager[598]: <info> (wlan1) supports 4 scan SSIDs
Jun 19 14:19:29 comp kernel: [   11.219878] r8169 0000:04:00.0: p33p1: link up
Jun 19 14:19:29 comp NetworkManager[598]: <info> (p33p1): carrier now ON (device state 20)
Jun 19 14:19:29 comp kernel: [   11.221910] ADDRCONF(NETDEV_CHANGE): p33p1: link becomes ready
Jun 19 14:19:29 comp NetworkManager[598]: <info> (p33p1): device state change: unavailable -> disconnected (reason 'carrier-changed') [20 30 40]
Jun 19 14:19:30 comp NetworkManager[598]: <info> Auto-activating connection 'xyz'.
Jun 19 14:19:30 comp NetworkManager[598]: <info> Activation (wlan0) starting connection 'xyz'
Jun 19 14:19:30 comp NetworkManager[598]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Jun 19 14:19:30 comp NetworkManager[598]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Jun 19 14:19:30 comp NetworkManager[598]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Jun 19 14:19:30 comp NetworkManager[598]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Jun 19 14:19:30 comp NetworkManager[598]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Jun 19 14:19:30 comp NetworkManager[598]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Jun 19 14:19:30 comp NetworkManager[598]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Jun 19 14:19:30 comp NetworkManager[598]: <info> Activation (wlan0/wireless): connection 'xyz' has security, and secrets exist.  No new secrets needed.
Jun 19 14:19:30 comp NetworkManager[598]: <info> Config: added 'ssid' value 'xyz'
Jun 19 14:19:30 comp NetworkManager[598]: <info> Config: added 'scan_ssid' value '1'
Jun 19 14:19:30 comp NetworkManager[598]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
Jun 19 14:19:30 comp NetworkManager[598]: <info> Config: added 'psk' value '<omitted>'
Jun 19 14:19:30 comp NetworkManager[598]: <info> Config: added 'proto' value 'WPA RSN'
Jun 19 14:19:30 comp NetworkManager[598]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Jun 19 14:19:30 comp NetworkManager[598]: <info> Config: set interface ap_scan to 1
Jun 19 14:19:30 comp NetworkManager[598]: <info> (wlan0): supplicant interface state: inactive -> scanning
Jun 19 14:19:31 comp avahi-daemon[595]: Registering new address record for fe80::ca60:ff:febc:f1db on p33p1.*.
Jun 19 14:19:31 comp systemd[1]: Startup finished in 2s 792ms 485us (kernel) + 2s 975ms 850us (initrd) + 6s 605ms 950us (userspace) = 12s 374ms 285us.
Jun 19 14:19:31 comp NetworkManager[598]: <info> (wlan0): supplicant interface state: scanning -> authenticating
Jun 19 14:19:31 comp NetworkManager[598]: <info> (wlan0): supplicant interface state: authenticating -> associating
Jun 19 14:19:31 comp kernel: [   12.856418] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Jun 19 14:19:31 comp NetworkManager[598]: <info> (wlan0): supplicant interface state: associating -> 4-way handshake
Jun 19 14:19:31 comp NetworkManager[598]: <info> (wlan0): supplicant interface state: 4-way handshake -> completed
Jun 19 14:19:31 comp NetworkManager[598]: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network 'xyz'.
Jun 19 14:19:31 comp NetworkManager[598]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.
Jun 19 14:19:31 comp NetworkManager[598]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...
Jun 19 14:19:31 comp NetworkManager[598]: <info> (wlan0): device state change: config -> ip-config (reason 'none') [50 70 0]
Jun 19 14:19:31 comp NetworkManager[598]: <info> Activation (wlan0) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
Jun 19 14:19:31 comp NetworkManager[598]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.
Jun 19 14:19:31 comp NetworkManager[598]: <info> Activation (wlan0) Stage 5 of 5 (IPv4 Commit) started...
Jun 19 14:19:31 comp avahi-daemon[595]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.4.
Jun 19 14:19:31 comp avahi-daemon[595]: New relevant interface wlan0.IPv4 for mDNS.
Jun 19 14:19:31 comp avahi-daemon[595]: Registering new address record for 192.168.2.4 on wlan0.IPv4.
Jun 19 14:19:32 comp NetworkManager[598]: <info> (wlan0): device state change: ip-config -> activated (reason 'none') [70 100 0]
Jun 19 14:19:32 comp NetworkManager[598]: <info> Activation (wlan0) successful, device activated.
Jun 19 14:19:32 comp NetworkManager[598]: <info> Activation (wlan0) Stage 5 of 5 (IPv4 Commit) complete.
Jun 19 14:19:32 comp dbus[676]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Jun 19 14:19:32 comp dbus-daemon[676]: dbus[676]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Jun 19 14:19:32 comp dbus-daemon[676]: dbus[676]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jun 19 14:19:32 comp dbus[676]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jun 19 14:21:13 comp NetworkManager[598]: <info> Auto-activating connection 'NON-WORKY'.
Jun 19 14:21:13 comp NetworkManager[598]: <info> Activation (wlan1) starting connection 'NON-WORKY'
Jun 19 14:21:13 comp NetworkManager[598]: <info> (wlan1): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Jun 19 14:21:13 comp NetworkManager[598]: <info> Activation (wlan1) Stage 1 of 5 (Device Prepare) scheduled...
Jun 19 14:21:13 comp NetworkManager[598]: <info> Activation (wlan1) Stage 1 of 5 (Device Prepare) started...
Jun 19 14:21:13 comp NetworkManager[598]: <info> Activation (wlan1) Stage 2 of 5 (Device Configure) scheduled...
Jun 19 14:21:13 comp NetworkManager[598]: <info> Activation (wlan1) Stage 1 of 5 (Device Prepare) complete.
Jun 19 14:21:13 comp NetworkManager[598]: <info> Activation (wlan1) Stage 2 of 5 (Device Configure) starting...
Jun 19 14:21:13 comp NetworkManager[598]: <info> (wlan1): device state change: prepare -> config (reason 'none') [40 50 0]
Jun 19 14:21:13 comp NetworkManager[598]: <info> Activation (wlan1/wireless): connection 'NON-WORKY' has security, and secrets exist.  No new secrets needed.
Jun 19 14:21:13 comp NetworkManager[598]: <info> Config: added 'ssid' value 'NON-WORKY'
Jun 19 14:21:13 comp NetworkManager[598]: <info> Config: added 'scan_ssid' value '1'
Jun 19 14:21:13 comp NetworkManager[598]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
Jun 19 14:21:13 comp NetworkManager[598]: <info> Config: added 'psk' value '<omitted>'
Jun 19 14:21:13 comp NetworkManager[598]: <info> Config: added 'proto' value 'WPA RSN'
Jun 19 14:21:13 comp NetworkManager[598]: <info> Activation (wlan1) Stage 2 of 5 (Device Configure) complete.
Jun 19 14:21:13 comp NetworkManager[598]: <info> Config: set interface ap_scan to 1
Jun 19 14:21:13 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: inactive -> scanning
Jun 19 14:21:14 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: scanning -> authenticating
Jun 19 14:21:15 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: authenticating -> associating
Jun 19 14:21:15 comp kernel: [  116.456176] ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
Jun 19 14:21:15 comp kernel: [  116.456325] cfg80211: Calling CRDA for country: DE
Jun 19 14:21:15 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: associating -> associated
Jun 19 14:21:15 comp kernel: [  116.473709] cfg80211: Regulatory domain changed to country: DE
Jun 19 14:21:15 comp kernel: [  116.473712] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
Jun 19 14:21:15 comp kernel: [  116.473717] cfg80211:   (2400000 KHz - 2483500 KHz @ 40000 KHz), (N/A, 2000 mBm)
Jun 19 14:21:15 comp kernel: [  116.473721] cfg80211:   (5150000 KHz - 5250000 KHz @ 40000 KHz), (N/A, 2000 mBm)
Jun 19 14:21:15 comp kernel: [  116.473724] cfg80211:   (5250000 KHz - 5350000 KHz @ 40000 KHz), (N/A, 2000 mBm)
Jun 19 14:21:15 comp kernel: [  116.473728] cfg80211:   (5470000 KHz - 5725000 KHz @ 40000 KHz), (N/A, 2698 mBm)
Jun 19 14:21:15 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: associated -> 4-way handshake
Jun 19 14:21:16 comp avahi-daemon[595]: Registering new address record for fe80::20e:e8ff:fedc:a924 on wlan1.*.
Jun 19 14:21:21 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: 4-way handshake -> disconnected
Jun 19 14:21:21 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: disconnected -> scanning
Jun 19 14:21:23 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: scanning -> authenticating
Jun 19 14:21:23 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: authenticating -> associating
Jun 19 14:21:23 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: associating -> associated
Jun 19 14:21:23 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: associated -> 4-way handshake
Jun 19 14:21:29 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: 4-way handshake -> disconnected
Jun 19 14:21:29 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: disconnected -> scanning
Jun 19 14:21:31 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: scanning -> authenticating
Jun 19 14:21:31 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: authenticating -> associating
Jun 19 14:21:31 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: associating -> associated
Jun 19 14:21:31 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: associated -> 4-way handshake
Jun 19 14:21:37 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: 4-way handshake -> disconnected
Jun 19 14:21:37 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: disconnected -> scanning
Jun 19 14:21:38 comp NetworkManager[598]: <warn> Activation (wlan1/wireless): association took too long.
Jun 19 14:21:38 comp NetworkManager[598]: <info> (wlan1): device state change: config -> need-auth (reason 'none') [50 60 0]
Jun 19 14:21:38 comp NetworkManager[598]: <warn> Activation (wlan1/wireless): asking for new secrets
Jun 19 14:21:38 comp NetworkManager[598]: <info> (wlan1): supplicant interface state: scanning -> disconnected
Jun 19 14:21:38 comp NetworkManager[598]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.

Comment 2 asdfx 2012-06-18 11:01:29 UTC

Apparently I can still connect even with 3.4.x through a rtl8187 device - since the AP is far away the connection isn't good enough to be usable - but at least this gives a clue that there's probably something wrong with the rt2860 stuff.

Comment 3 Stanislaw Gruszka 2012-06-20 15:04:56 UTC

What exactly chip is that (this information should be available in lsusb ) ?

Comment 4 asdfx 2012-06-20 18:34:05 UTC

148f:3070 Ralink Technology, Corp. RT2870/RT3070 Wireless Adapter
using these modules:

rt2800usb   
rt2x00usb
rt2800lib

Comment 5 Igor 2012-06-20 18:49:15 UTC

+1. RFRemix 17. Ralink RT2070 rt2800usb

Comment 6 Stanislaw Gruszka 2012-06-21 19:43:47 UTC

I have the same device, but I can not recreate the problem. However I think this is the issue with TX power settings. I prepared kernel which revert some TX power changes introduced in 3.4. Here is the kernel:

http://koji.fedoraproject.org/koji/taskinfo?taskID=4183660

Please check if it fixes the issue for you.

Comment 7 asdfx 2012-06-21 21:23:24 UTC

I still can't connect to that wlan - but now kde-networkmanager doesn't ask for the key again all the time. Ping times to another working wifi's AP increased.
But it appears with these changes now it actually tries to use dhclient.

dmesg:

[   10.874876] ADDRCONF(NETDEV_UP): wlan1: link is not ready
[   13.993658] wlan1: authenticate with MA:CA:DD:RE:SS
[   14.082987] wlan1: send auth to MA:CA:DD:RE:SS (try 1/3)
[   14.089564] wlan1: authenticated
[   14.142067] wlan1: associating with AP with corrupt beacon
[   14.142989] wlan1: associate with MA:CA:DD:RE:SS (try 1/3)
[   14.161991] wlan1: RX AssocResp from MA:CA:DD:RE:SS (capab=0x411 status=0 aid=2)
[   14.162000] wlan1: associated
[   21.766147] wlan1: authenticate with MA:CA:DD:RE:SS
[   21.851941] wlan1: send auth to MA:CA:DD:RE:SS (try 1/3)
[   21.853426] wlan1: authenticated
[   21.916917] wlan1: associating with AP with corrupt beacon
[   21.919129] wlan1: associate with MA:CA:DD:RE:SS (try 1/3)
[   21.937921] wlan1: RX AssocResp from MA:CA:DD:RE:SS (capab=0x411 status=0 aid=2)
[   21.937931] wlan1: associated
[   23.208943] wlan0: no IPv6 routers present
[   26.151252] wlan1: deauthenticated from MA:CA:DD:RE:SS (Reason: 15)
[   27.833494] wlan1: authenticate with MA:CA:DD:RE:SS
[   27.941375] wlan1: send auth to MA:CA:DD:RE:SS (try 1/3)
[   27.942817] wlan1: authenticated
[   28.001492] wlan1: associating with AP with corrupt beacon
[   28.002517] wlan1: associate with MA:CA:DD:RE:SS (try 1/3)
[   28.020484] wlan1: RX AssocResp from MA:CA:DD:RE:SS (capab=0x411 status=0 aid=2)
[   28.020493] wlan1: associated
[   34.376895] wlan1: deauthenticated from MA:CA:DD:RE:SS (Reason: 15)
[   36.074177] wlan1: authenticate with MA:CA:DD:RE:SS
[   36.163181] wlan1: send auth to MA:CA:DD:RE:SS (try 1/3)
[   36.164676] wlan1: authenticated
[   36.219629] wlan1: associating with AP with corrupt beacon
[   36.220668] wlan1: associate with MA:CA:DD:RE:SS (try 1/3)
[   36.238837] wlan1: RX AssocResp from MA:CA:DD:RE:SS (capab=0x411 status=0 aid=2)
[   36.238847] wlan1: associated
[   43.685871] wlan1: deauthenticated from MA:CA:DD:RE:SS (Reason: 6)
[   45.374854] wlan1: authenticate with MA:CA:DD:RE:SS
[   45.467326] wlan1: send auth to MA:CA:DD:RE:SS (try 1/3)
[   45.470898] wlan1: authenticated
[   45.522715] wlan1: associating with AP with corrupt beacon
[   45.523664] wlan1: associate with MA:CA:DD:RE:SS (try 1/3)
[   45.541659] wlan1: RX AssocResp from MA:CA:DD:RE:SS (capab=0x411 status=0 aid=2)
[   45.541668] wlan1: associated
[   62.348163] wlan1: deauthenticating from MA:CA:DD:RE:SS by local choice (reason=3)
[   66.689753] wlan1: authenticate with MA:CA:DD:RE:SS
[   66.793071] wlan1: send auth to MA:CA:DD:RE:SS (try 1/3)
[   66.795336] wlan1: authenticated
[   66.862468] wlan1: associating with AP with corrupt beacon
[   66.863453] wlan1: associate with MA:CA:DD:RE:SS (try 1/3)
[   66.882998] wlan1: RX AssocResp from MA:CA:DD:RE:SS (capab=0x411 status=0 aid=2)
[   66.883012] wlan1: associated
[   72.649156] SELinux: initialized (dev proc, type proc), uses genfs_contexts
[   79.613399] wlan1: deauthenticated from MA:CA:DD:RE:SS (Reason: 6)
[   81.310199] wlan1: authenticate with MA:CA:DD:RE:SS
[   81.402714] wlan1: send auth to MA:CA:DD:RE:SS (try 1/3)
[   81.404625] wlan1: authenticated
[   81.457938] wlan1: associating with AP with corrupt beacon
[   81.458919] wlan1: associate with MA:CA:DD:RE:SS (try 1/3)
[   81.477007] wlan1: RX AssocResp from MA:CA:DD:RE:SS (capab=0x411 status=0 aid=2)
[   81.477016] wlan1: associated
[  114.345348] wlan1: deauthenticating from MA:CA:DD:RE:SS by local choice (reason=3)
[  118.750912] wlan1: authenticate with MA:CA:DD:RE:SS
[  118.862177] wlan1: send auth to MA:CA:DD:RE:SS (try 1/3)
[  118.869962] wlan1: authenticated
[  118.927783] wlan1: associating with AP with corrupt beacon
[  118.928031] wlan1: associate with MA:CA:DD:RE:SS (try 1/3)
[  118.947308] wlan1: RX AssocResp from MA:CA:DD:RE:SS (capab=0x411 status=0 aid=2)
[  118.947322] wlan1: associated
[  164.344009] wlan1: deauthenticating from MA:CA:DD:RE:SS by local choice (reason=3)

messages:

Jun 23 01:06:14 comp dhclient[2619]: DHCPREQUEST on wlan1 to 255.255.255.255 port 67 (xid=0x975a2a5)
Jun 23 01:06:14 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: completed -> disconnected
Jun 23 01:06:14 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: disconnected -> scanning
Jun 23 01:06:16 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: scanning -> authenticating
Jun 23 01:06:16 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: authenticating -> associating
Jun 23 01:06:16 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: associating -> associated
Jun 23 01:06:16 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: associated -> 4-way handshake
Jun 23 01:06:22 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: 4-way handshake -> disconnected
Jun 23 01:06:22 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: disconnected -> scanning
Jun 23 01:06:24 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: scanning -> authenticating
Jun 23 01:06:24 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: authenticating -> associating
Jun 23 01:06:24 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: associating -> associated
Jun 23 01:06:24 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: associated -> 4-way handshake
Jun 23 01:06:24 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: 4-way handshake -> completed
Jun 23 01:06:25 comp dhclient[2619]: DHCPDISCOVER on wlan1 to 255.255.255.255 port 67 interval 7 (xid=0x7bc00a05)
Jun 23 01:06:30 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: completed -> disconnected
Jun 23 01:06:30 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: disconnected -> scanning
Jun 23 01:06:32 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: scanning -> authenticating
Jun 23 01:06:32 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: authenticating -> associating
Jun 23 01:06:32 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: associating -> associated
Jun 23 01:06:32 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: associated -> 4-way handshake
Jun 23 01:06:32 comp dhclient[2619]: DHCPDISCOVER on wlan1 to 255.255.255.255 port 67 interval 8 (xid=0x7bc00a05)
Jun 23 01:06:35 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: 4-way handshake -> completed
Jun 23 01:06:40 comp dbus-daemon[671]: ** Message: No devices in use, exit
Jun 23 01:06:40 comp dhclient[2619]: DHCPDISCOVER on wlan1 to 255.255.255.255 port 67 interval 13 (xid=0x7bc00a05)
Jun 23 01:06:41 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: completed -> disconnected
Jun 23 01:06:41 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: disconnected -> scanning
Jun 23 01:06:42 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: scanning -> authenticating
Jun 23 01:06:42 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: authenticating -> associating
Jun 23 01:06:42 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: associating -> associated                
Jun 23 01:06:43 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: associated -> 4-way handshake            
Jun 23 01:06:43 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: 4-way handshake -> completed             
Jun 23 01:06:53 comp dhclient[2619]: DHCPDISCOVER on wlan1 to 255.255.255.255 port 67 interval 8 (xid=0x7bc00a05)              
Jun 23 01:06:54 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: completed -> disconnected                
Jun 23 01:06:54 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: disconnected -> scanning                 
Jun 23 01:06:54 comp NetworkManager[589]: <warn> (wlan1): DHCPv4 request timed out.                                            
Jun 23 01:06:54 comp NetworkManager[589]: <info> (wlan1): canceled DHCP transaction, DHCP client pid 2619                      
Jun 23 01:06:55 comp NetworkManager[589]: <info> Activation (wlan1) Stage 4 of 5 (IPv4 Configure Timeout) scheduled...         
Jun 23 01:06:55 comp NetworkManager[589]: <info> Activation (wlan1) Stage 4 of 5 (IPv4 Configure Timeout) started...           
Jun 23 01:06:55 comp NetworkManager[589]: <info> (wlan1): device state change: ip-config -> failed (reason 'ip-config-unavailable') [70 120 5]                                                                                                                  
Jun 23 01:06:55 comp NetworkManager[589]: <warn> Activation (wlan1) failed for access point (XYZ)                     
Jun 23 01:06:55 comp NetworkManager[589]: <info> Marking connection 'XYZ' invalid.                                    
Jun 23 01:06:55 comp NetworkManager[589]: <warn> Activation (wlan1) failed.                                                    
Jun 23 01:06:55 comp NetworkManager[589]: <info> Activation (wlan1) Stage 4 of 5 (IPv4 Configure Timeout) complete.            
Jun 23 01:06:55 comp NetworkManager[589]: <info> (wlan1): device state change: failed -> disconnected (reason 'none') [120 30 0]                                                                                                                                
Jun 23 01:06:55 comp NetworkManager[589]: <info> (wlan1): deactivating device (reason 'none') [0]                              
Jun 23 01:06:55 comp NetworkManager[589]: <info> (wlan1): supplicant interface state: scanning -> disconnected

Comment 8 Stanislaw Gruszka 2012-06-21 23:26:11 UTC

Can you attach full dmesg ?

Comment 9 Igor 2012-06-22 14:25:37 UTC

Created attachment 593765 [details]
Ralink 2870, kernel 3.4.2

Comment 10 Stanislaw Gruszka 2012-06-22 14:29:12 UTC

I would like to see dmesg from test kernel from comment 6?

Comment 11 asdfx 2012-06-23 10:39:33 UTC

Created attachment 915468 [details]
Comment

(This comment was longer than 65,535 characters and has been moved to an attachment by Red Hat Bugzilla).

Comment 12 Igor 2012-06-23 10:59:25 UTC

Updated a kernel to 4.3. Everything works.

Comment 13 Stanislaw Gruszka 2012-06-24 10:11:56 UTC

asdfx, does update to 3.4.3 fix problem for you as well?

BTW: next time for providing dmesg, logs please use "Add an attachment" option, inlining logs make it harder to read and process (grep,sed, etc ...).

Comment 14 asdfx 2012-06-24 12:28:28 UTC

Sorry for that.
And no, even with 3.4.3 I still can't connect.

Comment 15 Stanislaw Gruszka 2012-06-25 13:18:55 UTC

Another shot in the dark ...

asdfx please test this kernel, it include patch for bug 828824, which perhaps could help here as well:
http://koji.fedoraproject.org/koji/taskinfo?taskID=4193085

Comment 16 asdfx 2012-06-25 22:23:06 UTC

Nope, no change at all.

I searched the web and also asked in #linux-wireless and found these two things: 


http://thread.gmane.org/gmane.linux.drivers.rt2x00.user/893/focus=916

and

http://permalink.gmane.org/gmane.linux.kernel.wireless.general/86327

this is, where corrupt beacon checking appears to be introduced, maybe this checks too much and keeps my wifi from connecting?

Comment 17 Stanislaw Gruszka 2012-07-09 10:14:30 UTC

(In reply to comment #16)
> http://thread.gmane.org/gmane.linux.drivers.rt2x00.user/893/focus=916
I reverted changes causing those TX power problems in test kernel from comment 6, 
it did not help.

> http://permalink.gmane.org/gmane.linux.kernel.wireless.general/86327
> 
> this is, where corrupt beacon checking appears to be introduced, maybe this
> checks too much and keeps my wifi from connecting?

I reverted this patch and lunch build here:
http://koji.fedoraproject.org/koji/taskinfo?taskID=4226637

Comment 18 Stanislaw Gruszka 2012-07-10 07:20:06 UTC

Any testing results from above kernel build?

Comment 19 asdfx 2012-07-11 19:29:24 UTC

Sorry Stanislaw,

apparently I'm now able to use 3.4.4-5.fc17 with the previously non-working network. BUT: wifi connectivity is still worse compared to 3.3.7 - I think I'm actually just lucky to have no interferences by neighbours, which were no problem with 3.3.7 before.

Tested another copying a bigger file through another wifi on the same channel - this made me immediatly lose the connection to the original wifi - this wasn't an issue with 3.3.7. After moving the wifis' channels away from eachother, no problem anymore.
Also it appears it's now only connecting at 28.8 Mb/s max.

So.. overall I think there are performance impacts, which happened somewhere from 3.3 to 3.4.
I will test the kernel in comment 6 again to see if that changes anything - since I'm entering in exams right now, I can't do much testing right now unfortunately.

Comment 20 asdfx 2012-08-25 22:33:57 UTC

Ok, I tried the kernel from comment 6 again - the problem persists. I can connect, but it's very unstable. Kernel 3.3.7 is far better - there I get a stable connection.

Comment 21 Stanislaw Gruszka 2013-01-24 13:28:46 UTC

Does it work on latest kernel? If not, I do not see any chance to fix this bug except doing bisection between good version - 3.3 and bad version - 3.4 . 

I described how to bisect kernel here: https://bugzilla.redhat.com/show_bug.cgi?id=637647#c1

Would be great if you can bisect problem and point bad commit, otherwise I'll close this bug as won't fix :-(

Comment 22 Stanislaw Gruszka 2013-01-24 13:45:52 UTC

(In reply to comment #21)
> I described how to bisect kernel here:
> https://bugzilla.redhat.com/show_bug.cgi?id=637647#c1
Since bisection need to be performed between 3.4 and 3.3, starting command will be like follow:

$ git bisect start
$ git bisect bad v3.4
$ git bisect good v3.3

Comment 23 Stanislaw Gruszka 2013-03-12 17:21:25 UTC

I'm sorry, but I do not see chances to fix this bug.