Bug 457197

Summary: 4965AGN wifi not working on T61 in specific situation
Product: [Fedora] Fedora Reporter: Eduards <edzis>
Component: NetworkManagerAssignee: Dan Williams <dcbw>
Status: CLOSED WONTFIX QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: low    
Version: 9CC: arxs, dcbw, matthewbstanton, wtogami
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2009-06-11 19:33:17 UTC Type: ---
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
wpa_supplicant log file in env. where wifi is not working with -dd switch enabled none

Description Eduards 2008-07-30 08:09:35 UTC 
From Bugzilla Helper:
User-Agent: Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US; rv:1.9.0.1) Gecko/2008070208 Firefox/3.0.1

Description of problem:
Env.: T61, Fedora9, latest iwlwifi, latest NetworkManager (0.7), kernel-2.6.25-11 (don't work with all 25 kernels, that's what I've tried), latest wpa_supplicant (0.6.3-6)

What I've tried so far is: whole bunch of kernels available in koji (all were 2.6.25 ones, I even tried 2.6.26 from F10), whole buch of NetworkManagers available in koji (all 0.7 svn ones), different versions of wpa_supplicant (even 0.5.3 or so). Nothing helped.
I even reinstalled F9 bunch of times (this was because I tried different OS which should work).

WiFi card is fully functional, even after hibernate. Starting up nicely, everything seems to be ok.
But issue I have is rather tricky, I would say. So I'll try to explain it.

At home I don't have hidden SIDs and booting computer in this env. makes WiFi work. I can see list of networks in NetworkManager, I can connect to them and so on. At this point I havent't connected to my workplace at all.

When I bring the computer to my workplace boot it up, I can connect to FREE wireless network using NetworkManger and my workplace network too. It's WPA2 Enterprise, hidden SID, PEAP, MSChapV2. It's working for the first time, I enter keyring pass, it saves conf etc. Nice so far. But there comes the bug, which occurs only when I have connected to workplace's WPA2 just once.

When I hibernate-resume, reboot computer in workplace, I cant' see any networks, I can't connect to any of FREE networks and my WPA2 network too. Wireless is broken! (I post the logs below)
When I hibernate-resume, reboot computer at home, everything seems to be fine and working, I can connect to WiFi no suspicious messages in logs.
Rather stupid :)

Ok, the logs. there are 2 logs I found suspicions. wpa_supplicant one and output from wpa_supplicant itself.
When there is no special logging enabled, all messages in wpa_suplicant log are the same:
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys

They are repeated hundreds of times. In between there are few CTRL-EVENT-SCAN-RESULTS messages too.

When I enabled the log of wpa_supplicant with -dd, I see this:
[root@tpevil eduards]# /usr/sbin/wpa_supplicant -c /etc/wpa_supplicant/wpa_supplicant.conf -u -f /var/log/wpa_supplicant.log -dd
ioctl[SIOCSIWAUTH]: Operation not supported
WEXT auth param 4 value 0x0 - ioctl[SIOCGIWSCAN]: Resource temporarily unavailable
ioctl[SIOCSIWENCODEEXT]: No such file or directory
ioctl[SIOCSIWENCODEEXT]: No such file or directory
ioctl[SIOCSIWENCODEEXT]: No such file or directory
^Cioctl[SIOCSIWAUTH]: Operation not supported
WEXT auth param 4 value 0x0 - 
[root@tpevil eduards]# 

Message "ioctl[SIOCSIWENCODEEXT]: No such file or directory" repeats itself like hundred times and appears at the same time as "CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys".

In the wpa_supplicant.log there are now additional information about connection:
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
Wireless event: cmd=0x8b15 len=24
Wireless event: new AP: 00:00:00:00:00:00
BSSID 00:00:00:00:00:00 blacklist count incremented to 41
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
Driver did not support SIOCSIWENCODEEXT
State: DISCONNECTED -> DISCONNECTED
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
WEXT: Operstate: linkmode=-1, operstate=5
EAPOL: External notification - portEnabled=0
EAPOL: External notification - portValid=0
Scan timeout - try to get results
Received 290 bytes of scan results (1 BSSes)
CTRL-EVENT-SCAN-RESULTS 
No APs found - clear blacklist and try again
Removed BSSID 00:00:00:00:00:00 from blacklist (clear)
No suitable AP found.
Setting scan request: 5 sec 0 usec
Setting scan request: 0 sec 0 usec
State: DISCONNECTED -> SCANNING
Starting AP scan (broadcast SSID)
Scan requested (ret=0) - scan timeout 30 seconds
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
Wireless event: cmd=0x8b15 len=24
Wireless event: new AP: 00:00:00:00:00:00
Added BSSID 00:00:00:00:00:00 into blacklist
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
Driver did not support SIOCSIWENCODEEXT
State: SCANNING -> DISCONNECTED
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
WEXT: Operstate: linkmode=-1, operstate=5
EAPOL: External notification - portEnabled=0
EAPOL: External notification - portValid=0
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
Wireless event: cmd=0x8b15 len=24
Wireless event: new AP: 00:00:00:00:00:00
BSSID 00:00:00:00:00:00 blacklist count incremented to 2
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
Driver did not support SIOCSIWENCODEEXT
State: DISCONNECTED -> DISCONNECTED
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
WEXT: Operstate: linkmode=-1, operstate=5
EAPOL: External notification - portEnabled=0
EAPOL: External notification - portValid=0
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
Wireless event: cmd=0x8b15 len=24
Wireless event: new AP: 00:00:00:00:00:00
BSSID 00:00:00:00:00:00 blacklist count incremented to 3
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys

"BSSID 00:00:00:00:00:00 blacklist count incremented to " goes up to some number and resets it and counts again.

I had this working in Fedora8, but after latest NetworkManager update and probably kernel or wpa_supplicant too, I have the same error there too, but as I can't bring wifi card back from hibernate in normal way, I don't use F8 anymore.

If you have questions, any request to any log files, feel free to ask, I'll provide whatever needed (except my credit card number of course :D)


Version-Release number of selected component (if applicable):


How reproducible:
Always


Steps to Reproduce:
Boot the computer in specific environment where this hidden SID is available


Actual Results:
Connection not established, logs full of what I described in "Description" field


Expected Results:
Connection established

Additional info:
Comment 1 Eduards 2008-07-31 07:02:00 UTC 
I'll gathered full logs after resume from hibernate in env. where wireless
doesn't work. I'll attach them to this bug.

And more details on the issue (to make things more clear):
Messages in logs appear only when I'm at workplace, that is - env. where that
hidden SID network exists.
As long as computer starts wireless messages in logs appear at a rate of about
one per second and wireless is non functional. I can't connect at all.
When booting everywhere else log has no such messages and wireless is functional.

It seems that settings are remembered (I see saved network in NM) and when
wireless sees that hidden network it somehow wants to disconnect from it like
every second. NM restart doesn't help, rmmod and modprobe too. Rebooting (as I
wrote earlier) doesn't help either.
And yes, I tried wireless-compat thing too, nothing helps. There should be bug
somewhere but the thing is I can't figure out where.
Comment 2 Eduards 2008-07-31 07:11:08 UTC 
Created attachment 313073 [details]
wpa_supplicant log file in env. where wifi is not working with -dd switch enabled

Promised log files.
wpa_supplicant binary does give the same output every second:
ioctl[SIOCSIWENCODEEXT]: No such file or directory
Dmesg has this (nothing really important I think):
Jul 31 09:31:10 tpevil NetworkManager: <info>  Waking up...
Jul 31 09:31:10 tpevil NetworkManager: <info>  (eth0): now managed
Jul 31 09:31:10 tpevil NetworkManager: <info>  (eth0): device state change: 1
-> 2
Jul 31 09:31:10 tpevil NetworkManager: <info>  (eth0): bringing up device.
Jul 31 09:31:10 tpevil kernel: ADDRCONF(NETDEV_UP): eth0: link is not ready
Jul 31 09:31:10 tpevil NetworkManager: <info>  (eth0): preparing device.
Jul 31 09:31:10 tpevil NetworkManager: <info>  (eth0): deactivating device.
Jul 31 09:31:10 tpevil NetworkManager: <info>  (wlan0): now managed
Jul 31 09:31:10 tpevil NetworkManager: <info>  (wlan0): device state change: 1
-> 2
Jul 31 09:31:10 tpevil NetworkManager: <info>  (wlan0): bringing up device.
Jul 31 09:31:10 tpevil kernel: ACPI: PCI Interrupt 0000:03:00.0[A] -> GSI 17
(level, low) -> IRQ 17
Jul 31 09:31:10 tpevil acpid: client connected from 2542[0:0]
Jul 31 09:31:11 tpevil kernel: Registered led device: iwl-phy0:radio
Jul 31 09:31:11 tpevil kernel: Registered led device: iwl-phy0:assoc
Jul 31 09:31:11 tpevil kernel: Registered led device: iwl-phy0:RX
Jul 31 09:31:11 tpevil kernel: Registered led device: iwl-phy0:TX
Jul 31 09:31:11 tpevil acpid: client connected from 2542[0:0]
Jul 31 09:31:11 tpevil kernel: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Jul 31 09:31:11 tpevil NetworkManager: <info>  (wlan0): preparing device.
Jul 31 09:31:11 tpevil NetworkManager: <info>  (wlan0): deactivating device.
Jul 31 09:31:11 tpevil kernel: hub 1-0:1.0: unable to enumerate USB device on
port 1
Jul 31 09:31:11 tpevil NetworkManager: <info>  (wlan0): device state change: 2
-> 3
Jul 31 09:31:11 tpevil NetworkManager: <info>  (wlan0): supplicant interface
state change: 1 -> 2.
Comment 3 Dan Williams 2008-10-20 15:27:12 UTC 
Is this still an issue with latest kernel, NM, and supplicant in F9 updates?  ie, 2.6.26.5-fc9 and later, wpa_supplicant 0.6.4 and later, and NM svn4022.4 and later?
Comment 4 Eduards 2008-11-06 12:29:41 UTC 
Hi,
sorry for late answer, somehow I felt this bug will be abandoned.

So, this is still an issue, but now there are different conditions.
Now I'm on ArchLinux (I had numerous problems with wifi, hibernate on F8 and F9 didn't suite me at all).
I'm building NM and wpa_supplicant myself now (to get latest features and hope bug is fixed).

Software:
1. kernel - 2.6.26-5 (ArchLinux one) (standard wifi is failing after 20 mins so...) I use compat-wireless from September 14, later releases just fails to load (I assume that this is because of new iwlagn thing), when compiling it gives out some agn_config warning (additional note: I can't use 2.6.27, coz my usb stops functioning after two(2) hibernates)
2. wpa_supplicant - 0.6.5
3. NM - it was around commit 4200 from SVN back then (when I tested this again)

It sort of worked for first time, so I thought bug disapeared, but once I use my ethernet and plug out cable, issue appears again - log shows this:
Oct 30 09:50:15 tpevil wlan0: authenticated
Oct 30 09:50:15 tpevil wlan0: associate with AP 00:xx:xx:xx:a6:f1
Oct 30 09:50:15 tpevil wlan0: associate with AP 00:xx:xx:xx:a6:f1
Oct 30 09:50:15 tpevil wlan0: deauthenticated
Oct 30 09:50:16 tpevil wlan0: authenticate with AP 00:xx:xx:xx:a6:f1
Oct 30 09:50:16 tpevil wlan0: authenticated
Oct 30 09:50:16 tpevil wlan0: associate with AP 00:xx:xx:xx:a6:f1
Oct 30 09:50:16 tpevil wlan0: associate with AP 00:xx:xx:xx:a6:f1
Oct 30 09:50:16 tpevil wlan0: deauthenticated

This goes on and on... No networks are found in between. When I go to other office that has the same hidden sid, it connects fine and is working nice.
So it seems the auth/deauth thing is coming from that one particular access point. 
I don't know how to track this better, if You have any suggestions, please tell me. When newest kernel will arrive, be it 2.6.27-xx or 2.6.28 I'll try to use that one hoping fingerprint reader will work and wireless too :)

regards
Kirurgs
Comment 5 Eduards 2008-11-10 11:06:09 UTC 
Hi,

2.6.27.5 came out and I tested this bug. It's still there.
This time no wireless-compat, just default modules. This doesn't seem to be NM bug, it seems it's wireless driver bug.

To test this You should:
1. connect to wireless network
2. plug in network cable, disconnect from wireless
3. plug out network cable
and here it goes.
In case You see this is not anyhow related to NM, can You please assign this bug to approriate team (wifi team?)

Thanx and regards
Kirurgs
Comment 6 Matthew Stanton 2008-12-19 07:41:56 UTC 
I can confirm this bug on fc10 with intel 4965AGN, fully updated as of Dec 17, 2008.  I can see networks after hibernation, but I cannot connect to them.  Works after a computer restart.
Comment 7 Dan Williams 2009-02-14 20:25:40 UTC 
Do latest kernels work better?  Like 2.6.27.12 from Fedora updates.  This bug is highly driver specific (not connecting after resume), and if recent kernels have the problem too, it may be good to test out software encryption rather than hardware accelerated encryption on the Intel wifi cards.
Comment 8 Niels Haase 2009-04-08 21:26:41 UTC 
Reporter, could you please reply to the previous question? If you won't reply in one month, I will have to close this bug as INSUFFICIENT_DATA. Thank you.

-- 
Fedora Bugzappers volunteer triage team
https://fedoraproject.org/wiki/BugZappers
Comment 9 Bug Zapper 2009-06-10 02:17:47 UTC 
This message is a reminder that Fedora 9 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 9.  It is Fedora's policy to close all
bug reports from releases that are no longer maintained.  At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '9'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 9's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 9 is end of life.  If you 
would still like to see this bug fixed and are able to reproduce it 
against a later version of Fedora please change the 'version' of this 
bug to the applicable version.  If you are unable to change the version, 
please add a comment here and someone will do it for you.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events.  Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping
Comment 10 Eduards 2009-06-11 19:33:17 UTC 
Hi!

Feel free to close the bug, I'm not using Fedora anyway, so I can't assist to further diagnostics.
I might use F11 soon, if bug will happen there, I'll fill a new bug.

regards
Kirurgs