Bug 490493 - NetworkManager disconnects/reconnects every 2 minutes and sometimes gets "mad"
Summary: NetworkManager disconnects/reconnects every 2 minutes and sometimes gets "mad"
Status: CLOSED DUPLICATE of bug 478686
Alias: None
Product: Fedora
Classification: Fedora
Component: NetworkManager
Version: 10
Hardware: i686
OS: Linux
low
medium
Target Milestone: ---
Assignee: Dan Williams
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Keywords:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2009-03-16 17:37 UTC by Dag
Modified: 2013-04-08 21:03 UTC (History)
10 users (show)

(edit)
Clone Of:
(edit)
Last Closed: 2009-10-15 05:18:35 UTC


Attachments (Terms of Use)

Description Dag 2009-03-16 17:37:41 UTC
Description of problem:
NetworkManager disconnects from wifi *exactly* every 2 minutes.
If I try to connect "by hand" with NetworkManager stopped, it almost never disconnects (few times an hour).
Sometimes NetworkManager also gets completely "mad" disconnecting/reconnceting every 1 to 5 seconds: wifi is then unusable.

Version-Release number of selected component (if applicable):
NetworkManager-0.7.0.99-3.fc10.i386
kernel 2.6.27.19-170.2.35.fc10.i686
=> lspci | grep Wireless
02:02.0 Network controller: Intel Corporation PRO/Wireless 2915ABG [Calexico2] Network Connection (rev 05)



How reproducible:
Always: disconnecting/reconnecting *exactly* every 2 minutes
Always: NetworkManager is disconnecting/reconnecting wifi (random, but few times per hour).
Sometimes : NetworkManager goes "mad" and connect/disconnect every 1 to 5 seconds

Steps to Reproduce:
1. Connect to a wifi AP via NetworkManager (mine is hidden SSID, WPA personal TKIP/AES, DHCP)
2. check the quality of the signal: iwlist eth1 scan: Quality=97/100  Signal level=-27 dBm
3. start a tail -f /var/log/messages
4. watch NetworkManager disconnect/reconnect wifi every 2 minutes

Actual results:
- NetworkManager disconnects wifi every 2 minutes exactly
- NetworkManager sometimes gets "mad"

Expected results:
- NetworkManager shouldn't disconnect anything

Additional info:
here is a log session (tail -f /var/log/messages):
   1.
      Mar 16 16:38:20 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  completed -> disconnected
   2.
      Mar 16 16:38:20 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  disconnected -> scanning
   3.
      Mar 16 16:38:26 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  scanning -> associating
   4.
      Mar 16 16:38:27 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  associating -> associated
   5.
      Mar 16 16:38:28 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  associated -> 4-way handshake
   6.
      Mar 16 16:38:28 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  4-way handshake -> group handshake
   7.
      Mar 16 16:38:29 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  group handshake -> completed
   8.
      Mar 16 16:40:20 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  completed -> disconnected
   9.
      Mar 16 16:40:20 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  disconnected -> scanning
  10.
      Mar 16 16:40:21 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  scanning -> associating
  11.
      Mar 16 16:40:21 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  associating -> associated
  12.
      Mar 16 16:40:21 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  associated -> 4-way handshake
  13.
      Mar 16 16:40:21 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  4-way handshake -> group handshake
  14.
      Mar 16 16:40:22 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  group handshake -> completed
  15.
      Mar 16 16:40:26 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  completed -> disconnected
  16.
      Mar 16 16:40:26 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  disconnected -> scanning
  17.
      Mar 16 16:40:27 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  scanning -> associating
  18.
      Mar 16 16:40:27 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  associating -> associated
  19.
      Mar 16 16:40:27 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  associated -> 4-way handshake
  20.
      Mar 16 16:40:27 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  4-way handshake -> group handshake
  21.
      Mar 16 16:40:28 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  group handshake -> completed
  22.
      Mar 16 16:42:20 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  completed -> disconnected
  23.
      Mar 16 16:42:20 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  disconnected -> scanning
  24.
      Mar 16 16:42:21 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  scanning -> associating
  25.
      Mar 16 16:42:21 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  associating -> associated
  26.
      Mar 16 16:42:21 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  associated -> 4-way handshake
  27.
      Mar 16 16:42:21 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  4-way handshake -> group handshake
  28.
      Mar 16 16:42:22 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  group handshake -> completed
  29.
      Mar 16 16:44:20 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  completed -> disconnected
  30.
      Mar 16 16:44:20 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  disconnected -> scanning
  31.
      Mar 16 16:44:26 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  scanning -> associating
  32.
      Mar 16 16:44:27 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  associating -> associated
  33.
      Mar 16 16:44:28 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  associated -> 4-way handshake
  34.
      Mar 16 16:44:28 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  4-way handshake -> group handshake
  35.
      Mar 16 16:44:29 microlaptop NetworkManager: <info>  (eth1): supplicant connection state:  group handshake -> completed


When NetworkManager is stopped (/etc/init.d/NetworkManager stop) and the wifi connection is initiated "by hand" it randomly disconnects/reconnects several times an hour but no more "2 minutes stuff".

My dmesg shows several of these lines (doesn't seem to happen after boot time):
ipw2200: Failed to send SYSTEM_CONFIG: Already sending a command.

Kismet says I'm alone on my wifi channel (fixed channel).

This behaviour ("2 minutes" and "mad") do not happen on another computer also connected to the same wifi AP (running Fedora9 i386 up to date using NetworkManager). This computer gets disconnected a few times per hour though.

My Fedora is up to date.

Those connections/disconnections can expose my network to some cracking.

Comment 1 Dan Williams 2009-03-16 19:33:38 UTC
Sounds like your AP (or the driver) is killing the connection due to periodic scans, which back off to a maximum 2 minute interval.  There's no real reason this should be happening other than a driver bug.  But a few questions:

1) has this always happened?  or has it just started happening?  NM hasn't changed it's scan behavior in a long long time, so if it just started happening, I'd suspect either AP changes or driver changes.

2) What wifi card is the "other computer" that is OK using?

3) Can you check how long the card takes to do a scan for me?  In a root terminal, do the following
   a) service NetworkManager stop
   b) killall -TERM wpa_supplicant
   c) time /sbin/iwlist eth1 scan
 and report the time printed out in (c), which will be something like:

real	0m0.255s
user	0m0.001s
sys	0m0.002s

Your 2915 is an a/b/g card, thus supports more channels and thus a scan could take longer.  If the AP thinks you're gone long enough, or the driver has a bug where it thinks it hasn't heard from the AP recently, it could disconnect you.

I do have a 2915 somewhere, so I can try to reproduce the issue this week.

Comment 2 Niels Haase 2009-04-07 20:27:00 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 3 Andrej Prsa 2009-04-28 23:35:20 UTC
I'm Ubuntu 9.04 user with a similar wifi (Intel 2200BG, using ipw2200) and I am seeing the same 1-5 second cycle:

Apr 28 19:14:12 altair NetworkManager: <info>  (eth1): supplicant connection state:  completed -> disconnected 
Apr 28 19:14:13 altair NetworkManager: <info>  (eth1): supplicant connection state:  disconnected -> scanning 
Apr 28 19:14:13 altair NetworkManager: <info>  (eth1): supplicant connection state:  scanning -> associating 
Apr 28 19:14:13 altair NetworkManager: <info>  (eth1): supplicant connection state:  associating -> associated 
Apr 28 19:14:13 altair NetworkManager: <info>  (eth1): supplicant connection state:  associated -> 4-way handshake 
Apr 28 19:14:13 altair NetworkManager: <info>  (eth1): supplicant connection state:  4-way handshake -> group handshake 
Apr 28 19:14:13 altair NetworkManager: <info>  (eth1): supplicant connection state:  group handshake -> completed 

This happened after ~2 hours of regular use, lasted for ~10 minutes and then stabilized again. I suspect it has to do with ipw2200. Here's info on my system and my wifi:

uname -a
Linux altair 2.6.28-11-generic #42-Ubuntu SMP Fri Apr 17 01:57:59 UTC 2009 i686 GNU/Linux

lspci -vvv
02:04.0 Network controller: Intel Corporation PRO/Wireless 2200BG [Calexico2] Network Connection (rev 05)
	Subsystem: Hewlett-Packard Company Device 12f6
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 64 (750ns min, 6000ns max), Cache Line Size: 64 bytes
	Interrupt: pin A routed to IRQ 21
	Region 0: Memory at d0000000 (32-bit, non-prefetchable) [size=4K]
	Capabilities: <access denied>
	Kernel driver in use: ipw2200
	Kernel modules: ipw2200

iwlist scan time:
real	0m0.004s
user	0m0.000s
sys	0m0.004s

Please let me know if I can help with any further info.

Comment 4 Christer Weinigel 2009-05-06 02:40:29 UTC
I am seeing the same problem with an Atheros card on a IBM Thinkpad X40 laptop and using WEP encryption.  If I recall correcly, I've seen the same problem at work with WPA.

02:02.0 Ethernet controller [0200]: Atheros Communications Inc. AR5212 802.11ab)

Here's some messages from my syslog, as you can see the interval seems to be N*60 seconds, and sometimes it is as frequent as every other minute, at other times it can take 9 minutes between the drops:

May  6 04:17:50 grue NetworkManager: <info>  (wlan0): supplicant connection state:  completed -> disconnected
May  6 04:17:50 grue NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> scanning
May  6 04:17:51 grue NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> associated
May  6 04:17:51 grue NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> completed

May  6 04:26:50 grue NetworkManager: <info>  (wlan0): supplicant connection state:  completed -> disconnected
May  6 04:26:50 grue NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> scanning
May  6 04:26:51 grue NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> associated
May  6 04:26:51 grue NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> completed

May  6 04:34:50 grue NetworkManager: <info>  (wlan0): supplicant connection state:  completed -> disconnected
May  6 04:34:50 grue NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> scanning
May  6 04:34:51 grue NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> associated
May  6 04:34:51 grue NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> completed

May  6 04:36:50 grue NetworkManager: <info>  (wlan0): supplicant connection state:  completed -> disconnected
May  6 04:36:50 grue NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> scanning
May  6 04:36:51 grue NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> associated
May  6 04:36:51 grue NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> completed

Comment 5 Jason Haar 2009-05-18 19:51:03 UTC
I think I'm a "me too"

I've got a Dell D430 laptop with an Intel Corporation PRO/Wireless 3945ABG (iwl3945) and sometimes I see it re-requesting via DHCP for its address every 2-3 seconds. syslog on the FC11 laptop shows:

May 19 07:46:11 tnz-jhaar-dell dhclient: DHCPREQUEST on wlan0 to 192.168.248.3 port 67
May 19 07:46:23 tnz-jhaar-dell dhclient: DHCPREQUEST on wlan0 to 192.168.248.3 port 67
May 19 07:46:42 tnz-jhaar-dell dhclient: DHCPREQUEST on wlan0 to 192.168.248.3 port 67


- nothing else. No kernel errors or any indication of a reason to do this.

Similarly, the DHCP server shows these requests coming through, and the logs on the Cisco Access Point show NOTHING - no indication why this is happening. The AP is around 2feet from my laptop, it's the only ESSID I can "see" and I'm the only user.

Assuming everyone on this ticket is experiencing the same issue, I'd say this wasn't a wireless driver problem - but something more in userspace?

BTW, I see no evidence of an issue. Other than the loss of a wee bit of syslog diskspace, there appears to be no actual problem for me.

Comment 6 Renich Bon Ciric 2009-06-10 07:39:07 UTC
Here're my two cents:

# lspci
02:06.0 Ethernet controller: Atheros Communications Inc. Atheros AR5001X+ Wireless Network Adapter (rev 01)

# I got this output from running 
wpa_supplicant -c /etc/wpa_config/someconfig.conf -i wlan0 -d

# This happens very often and, then, it reconnects

RTM_NEWLINK: operstate=1 ifi_flags=0x1043 ([UP][RUNNING])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
Wireless event: cmd=0x8b15 len=24
Wireless event: new AP: 00:00:00:00:00:00
Setting scan request: 0 sec 100000 usec
Added BSSID 00:0e:3b:07:a8:55 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
ioctl[SIOCSIWENCODEEXT]: No such file or directory
Driver did not support SIOCSIWENCODEEXT
State: COMPLETED -> DISCONNECTED
wpa_driver_wext_set_operstate: operstate 1->0 (DORMANT)
WEXT: Operstate: linkmode=-1, operstate=5
EAPOL: External notification - portEnabled=0
EAPOL: SUPP_PAE entering state DISCONNECTED
EAPOL: SUPP_BE entering state INITIALIZE
EAPOL: External notification - portValid=0
EAPOL: External notification - EAP success=0
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
State: DISCONNECTED -> SCANNING
Starting AP scan (broadcast SSID)
Scan requested (ret=0) - scan timeout 30 seconds
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
Wireless event: cmd=0x8b19 len=16
Received 3746 bytes of scan results (11 BSSes)
CTRL-EVENT-SCAN-RESULTS 
Selecting BSS from priority group 0
Try to find WPA-enabled AP
0: 00:0e:3b:07:a8:55 ssid='PentExtender1' wpa_ie_len=22 rsn_ie_len=0 caps=0x11
   selected based on WPA IE
   selected WPA AP 00:0e:3b:07:a8:55 ssid='PentExtender1'
Trying to associate with 00:0e:3b:07:a8:55 (SSID='PentExtender1' freq=2462 MHz)
Cancelling scan request
WPA: clearing own WPA/RSN IE
Automatic auth_alg selection: 0x1
WPA: using IEEE 802.11i/D3.0
WPA: Selected cipher suites: group 8 pairwise 8 key_mgmt 2 proto 1
WPA: set AP WPA IE - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
WPA: clearing AP RSN IE
WPA: using GTK TKIP
WPA: using PTK TKIP
WPA: using KEY_MGMT WPA-PSK
WPA: Set own WPA IE default - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
No keys have been configured - skip key clearing
wpa_driver_wext_set_drop_unencrypted
State: SCANNING -> ASSOCIATING
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
WEXT: Operstate: linkmode=-1, operstate=5
wpa_driver_wext_associate
wpa_driver_wext_set_psk
Setting authentication timeout: 20 sec 0 usec
EAPOL: External notification - EAP success=0
EAPOL: External notification - EAP fail=0
EAPOL: External notification - portControl=Auto
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
Wireless event: cmd=0x8b04 len=16
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
Wireless event: cmd=0x8b15 len=24
Wireless event: new AP: 00:00:00:00:00:00
BSSID 00:0e:3b:07:a8:55 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
ioctl[SIOCSIWENCODEEXT]: No such file or directory
Driver did not support SIOCSIWENCODEEXT
State: ASSOCIATING -> 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
EAPOL: External notification - EAP success=0
Authentication with 00:00:00:00:00:00 timed out.
Added BSSID 00:00:00:00:00:00 into blacklist
No keys have been configured - skip key clearing
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
EAPOL: External notification - EAP success=0
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])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
Wireless event: cmd=0x8b19 len=16
Scan results did not fit - trying larger buffer (8192 bytes)
Received 5039 bytes of scan results (14 BSSes)
CTRL-EVENT-SCAN-RESULTS 
Selecting BSS from priority group 0
Try to find WPA-enabled AP
0: 00:0e:3b:07:a8:55 ssid='PentExtender1' wpa_ie_len=22 rsn_ie_len=0 caps=0x11
   skip - blacklisted
1: 00:1a:c4:c4:70:a9 ssid='Penthouse' wpa_ie_len=22 rsn_ie_len=0 caps=0x11
   skip - SSID mismatch
2: 00:23:6c:bf:7b:69 ssid='Notaria 85n' wpa_ie_len=0 rsn_ie_len=20 caps=0x11
   skip - SSID mismatch
3: 00:1f:b3:8a:e2:91 ssid=' ' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - no WPA/RSN IE
4: 00:1f:b3:1a:5e:41 ssid=' ' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - no WPA/RSN IE
5: 00:1f:b3:d3:c0:19 ssid='INFINITUM3869' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - no WPA/RSN IE
6: 00:1f:b3:8a:e2:91 ssid='' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - no WPA/RSN IE
7: 00:1f:b3:1a:5e:41 ssid='' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - no WPA/RSN IE
8: 00:1c:0e:d4:e2:40 ssid='ASFG-WLAN' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - no WPA/RSN IE
9: 00:1c:b0:ea:c9:30 ssid='ASFG-WLAN' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - no WPA/RSN IE
10: 00:24:51:c9:05:10 ssid='ASFG-WLAN' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - no WPA/RSN IE
11: 00:10:e7:f5:da:8b ssid='Bikku' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - no WPA/RSN IE
12: 00:02:2d:c4:45:42 ssid='PFeAmQP4' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - no WPA/RSN IE
13: 00:02:2d:3d:f6:ba ssid=' ' wpa_ie_len=0 rsn_ie_len=0 caps=0x1
   skip - no WPA/RSN IE
Try to find non-WPA AP
0: 00:0e:3b:07:a8:55 ssid='PentExtender1' wpa_ie_len=22 rsn_ie_len=0 caps=0x11
   skip - blacklisted
1: 00:1a:c4:c4:70:a9 ssid='Penthouse' wpa_ie_len=22 rsn_ie_len=0 caps=0x11
   skip - SSID mismatch
2: 00:23:6c:bf:7b:69 ssid='Notaria 85n' wpa_ie_len=0 rsn_ie_len=20 caps=0x11
   skip - SSID mismatch
3: 00:1f:b3:8a:e2:91 ssid=' ' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - SSID mismatch
4: 00:1f:b3:1a:5e:41 ssid=' ' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - SSID mismatch
5: 00:1f:b3:d3:c0:19 ssid='INFINITUM3869' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - SSID mismatch
6: 00:1f:b3:8a:e2:91 ssid='' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - SSID mismatch
7: 00:1f:b3:1a:5e:41 ssid='' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - SSID mismatch
8: 00:1c:0e:d4:e2:40 ssid='ASFG-WLAN' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - SSID mismatch
9: 00:1c:b0:ea:c9:30 ssid='ASFG-WLAN' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - SSID mismatch
10: 00:24:51:c9:05:10 ssid='ASFG-WLAN' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - SSID mismatch
11: 00:10:e7:f5:da:8b ssid='Bikku' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - SSID mismatch
12: 00:02:2d:c4:45:42 ssid='PFeAmQP4' wpa_ie_len=0 rsn_ie_len=0 caps=0x11
   skip - SSID mismatch
13: 00:02:2d:3d:f6:ba ssid=' ' wpa_ie_len=0 rsn_ie_len=0 caps=0x1
   skip - SSID mismatch
No APs found - clear blacklist and try again
Removed BSSID 00:00:00:00:00:00 from blacklist (clear)
Removed BSSID 00:0e:3b:07:a8:55 from blacklist (clear)
Selecting BSS from priority group 0
Try to find WPA-enabled AP
0: 00:0e:3b:07:a8:55 ssid='PentExtender1' wpa_ie_len=22 rsn_ie_len=0 caps=0x11
   selected based on WPA IE
   selected WPA AP 00:0e:3b:07:a8:55 ssid='PentExtender1'
Trying to associate with 00:0e:3b:07:a8:55 (SSID='PentExtender1' freq=2462 MHz)
Cancelling scan request
WPA: clearing own WPA/RSN IE
Automatic auth_alg selection: 0x1
WPA: using IEEE 802.11i/D3.0
WPA: Selected cipher suites: group 8 pairwise 8 key_mgmt 2 proto 1
WPA: set AP WPA IE - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
WPA: clearing AP RSN IE
WPA: using GTK TKIP
WPA: using PTK TKIP
WPA: using KEY_MGMT WPA-PSK
WPA: Set own WPA IE default - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
No keys have been configured - skip key clearing
wpa_driver_wext_set_drop_unencrypted
State: SCANNING -> ASSOCIATING
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
WEXT: Operstate: linkmode=-1, operstate=5
wpa_driver_wext_associate
wpa_driver_wext_set_psk
Setting authentication timeout: 20 sec 0 usec
EAPOL: External notification - EAP success=0
EAPOL: External notification - EAP fail=0
EAPOL: External notification - portControl=Auto
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
Wireless event: cmd=0x8b04 len=16
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
Wireless event: cmd=0x8c02 len=161
Association info event
req_ies - hexdump(len=49): 00 0d 50 65 6e 74 45 78 74 65 6e 64 65 72 31 01 08 0c 12 18 24 30 48 60 6c dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
resp_ies - hexdump(len=10): 01 08 8c 92 98 a4 b0 48 60 6c
WPA: set own WPA/RSN IE - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
Wireless event: cmd=0x8b15 len=24
Wireless event: new AP: 00:0e:3b:07:a8:55
State: ASSOCIATING -> ASSOCIATED
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
WEXT: Operstate: linkmode=-1, operstate=5
Associated to a new BSS: BSSID=00:0e:3b:07:a8:55
No keys have been configured - skip key clearing
Associated with 00:0e:3b:07:a8:55
WPA: Association event - clear replay counter
WPA: Clear old PTK
EAPOL: External notification - portEnabled=0
EAPOL: External notification - portValid=0
EAPOL: External notification - EAP success=0
EAPOL: External notification - portEnabled=1
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: enable timer tick
EAPOL: SUPP_BE entering state IDLE
Setting authentication timeout: 10 sec 0 usec
Cancelling scan request
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
RX EAPOL from 00:0e:3b:07:a8:55
Setting authentication timeout: 10 sec 0 usec
IEEE 802.1X RX: version=1 type=3 length=95
  EAPOL-Key type=254
  key_info 0x89 (ver=1 keyidx=0 rsvd=0 Pairwise Ack)
  key_length=32 key_data_length=0
  replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_nonce - hexdump(len=32): cf cb 67 42 5b 51 23 36 65 c3 44 e2 10 1c 87 a0 a3 47 fe aa 15 63 65 cb 3d cb ef 9b 6e a7 0c 6c
  key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
State: ASSOCIATED -> 4WAY_HANDSHAKE
WPA: RX message 1 of 4-Way Handshake from 00:0e:3b:07:a8:55 (ver=1)
WPA: Renewed SNonce - hexdump(len=32): b8 38 71 55 34 57 1f 93 78 a4 03 ba 3b 12 a2 ed f6 53 e5 7f 6d 85 7d c2 40 ea 32 8d 8b 5f 63 6e
WPA: PTK derivation - A1=00:0d:88:c8:85:98 A2=00:0e:3b:07:a8:55
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=64): [REMOVED]
WPA: WPA IE for msg 2/4 - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
WPA: Sending EAPOL-Key 2/4
RX EAPOL from 00:0e:3b:07:a8:55
IEEE 802.1X RX: version=1 type=3 length=119
  EAPOL-Key type=254
  key_info 0x1c9 (ver=1 keyidx=0 rsvd=0 Pairwise Install Ack MIC)
  key_length=32 key_data_length=24
  replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
  key_nonce - hexdump(len=32): cf cb 67 42 5b 51 23 36 65 c3 44 e2 10 1c 87 a0 a3 47 fe aa 15 63 65 cb 3d cb ef 9b 6e a7 0c 6c
  key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_mic - hexdump(len=16): db 9b 44 3a 05 d0 8b 32 c9 a8 3b e5 ba 76 f8 bd
State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
WPA: RX message 3 of 4-Way Handshake from 00:0e:3b:07:a8:55 (ver=1)
WPA: IE KeyData - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
WPA: Sending EAPOL-Key 4/4
WPA: Installing PTK to the driver.
WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
wpa_driver_wext_set_key: alg=2 key_idx=0 set_tx=1 seq_len=6 key_len=32
State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
RX EAPOL from 00:0e:3b:07:a8:55
IEEE 802.1X RX: version=1 type=3 length=127
  EAPOL-Key type=254
  key_info 0x391 (ver=1 keyidx=1 rsvd=0 Group Ack MIC Secure)
  key_length=32 key_data_length=32
  replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 04
  key_nonce - hexdump(len=32): cf cb 67 42 5b 51 23 36 65 c3 44 e2 10 1c 87 a0 a3 47 fe aa 15 63 65 cb 3d cb ef 9b 6e a7 0c 6e
  key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_mic - hexdump(len=16): 1e bb f4 04 af 2c c1 01 35 ab 31 20 3e b3 06 3d
WPA: RX message 1 of Group Key Handshake from 00:0e:3b:07:a8:55 (ver=1)
State: GROUP_HANDSHAKE -> GROUP_HANDSHAKE
WPA: Group Key - hexdump(len=32): [REMOVED]
WPA: Installing GTK to the driver (keyidx=1 tx=0 len=32).
WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
wpa_driver_wext_set_key: alg=2 key_idx=1 set_tx=0 seq_len=6 key_len=32
WPA: Sending EAPOL-Key 2/2
WPA: Key negotiation completed with 00:0e:3b:07:a8:55 [PTK=TKIP GTK=TKIP]
Cancelling authentication timeout
State: GROUP_HANDSHAKE -> COMPLETED
CTRL-EVENT-CONNECTED - Connection to 00:0e:3b:07:a8:55 completed (reauth) [id=0 id_str=]
wpa_driver_wext_set_operstate: operstate 0->1 (UP)
WEXT: Operstate: linkmode=-1, operstate=6
EAPOL: External notification - portValid=1
EAPOL: External notification - EAP success=1
EAPOL: SUPP_PAE entering state AUTHENTICATING
EAPOL: SUPP_BE entering state SUCCESS
EAP: EAP entering state DISABLED
EAPOL: SUPP_PAE entering state AUTHENTICATED
EAPOL: SUPP_BE entering state IDLE
EAPOL authentication completed successfully
RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
EAPOL: startWhen --> 0
EAPOL: disable timer tick

Comment 7 Tim Wilkinson 2009-06-11 17:33:36 UTC
I see this issue regularly using FC10 on a Lenovo T61 laptop. Indeed, every two minutes.

Jun 11 13:22:24 hagrid NetworkManager: <info>  (wlan0): supplicant connection state:  associating -> associated
Jun 11 13:22:24 hagrid NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> completed
Jun 11 13:22:24 hagrid NetworkManager: <info>  (wlan0): supplicant connection state:  completed -> disconnected
Jun 11 13:22:24 hagrid NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> scanning
Jun 11 13:22:25 hagrid NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> associated
Jun 11 13:22:25 hagrid NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> completed
Jun 11 13:24:21 hagrid NetworkManager: <info>  (wlan0): supplicant connection state:  completed -> associating
Jun 11 13:24:21 hagrid NetworkManager: <info>  (wlan0): supplicant connection state:  associating -> associated

Comment 8 Tim Wilkinson 2009-06-11 17:45:43 UTC
03:00.0 Network controller: Intel Corporation PRO/Wireless 3945ABG [Golan] Network Connection (rev 02)

$ service NetworkManager stop
Stopping NetworkManager daemon:                            [  OK  ]

$ killall -TERM wpa_supplicant

$ time /sbin/iwlist wlan0 scan
wlan0     Interface doesn't support scanning : Network is down

real	0m0.002s
user	0m0.000s
sys	0m0.003s

$ service NetworkManager start
Setting network parameters...                              [  OK  ]
Starting NetworkManager daemon:                            [  OK  ]

$ time /sbin/iwlist wlan0 scan
wlan0     Scan completed :
          Cell 01 - Address: 00:1F:6C:CA:7B:E0
                    ESSID:"rh-wireless"
                    Mode:Master
                    Channel:3
                    Frequency:2.422 GHz (Channel 3)
                    Quality=31/100  Signal level:-90 dBm  Noise level=-127 dBm
                    Encryption key:on
                    Bit Rates:1 Mb/s; 2 Mb/s; 5.5 Mb/s; 6 Mb/s; 9 Mb/s
                              11 Mb/s; 12 Mb/s; 18 Mb/s; 24 Mb/s; 36 Mb/s
                              48 Mb/s; 54 Mb/s
                    Extra:tsf=000005c11016e18c
                    Extra: Last beacon: 4193ms ago
          Cell 02 - Address: 00:1E:F7:55:A3:70
                    ESSID:"rh-wireless"
                    Mode:Master
                    Channel:4
                    Frequency:2.427 GHz (Channel 4)
                    Quality=46/100  Signal level:-81 dBm  Noise level=-127 dBm
                    Encryption key:on
                    Bit Rates:1 Mb/s; 2 Mb/s; 5.5 Mb/s; 6 Mb/s; 9 Mb/s
                              11 Mb/s; 12 Mb/s; 18 Mb/s; 24 Mb/s; 36 Mb/s
                              48 Mb/s; 54 Mb/s
                    Extra:tsf=000005c1114c418c
                    Extra: Last beacon: 3952ms ago
          Cell 03 - Address: 00:1E:F7:55:A8:10
                    ESSID:"rh-wireless"
                    Mode:Master
                    Channel:4
                    Frequency:2.427 GHz (Channel 4)
                    Quality=31/100  Signal level:-90 dBm  Noise level=-127 dBm
                    Encryption key:on
                    Bit Rates:1 Mb/s; 2 Mb/s; 5.5 Mb/s; 6 Mb/s; 9 Mb/s
                              11 Mb/s; 12 Mb/s; 18 Mb/s; 24 Mb/s; 36 Mb/s
                              48 Mb/s; 54 Mb/s
                    Extra:tsf=000005c1124c81d0
                    Extra: Last beacon: 3812ms ago
          Cell 04 - Address: 00:1F:6C:CA:7E:40
                    ESSID:"rh-wireless"
                    Mode:Master
                    Channel:8
                    Frequency:2.447 GHz (Channel 8)
                    Quality=76/100  Signal level:-58 dBm  Noise level=-127 dBm
                    Encryption key:on
                    Bit Rates:1 Mb/s; 2 Mb/s; 5.5 Mb/s; 6 Mb/s; 9 Mb/s
                              11 Mb/s; 12 Mb/s; 18 Mb/s; 24 Mb/s; 36 Mb/s
                              48 Mb/s; 54 Mb/s
                    Extra:tsf=000005c1105ba253
                    Extra: Last beacon: 219ms ago
          Cell 05 - Address: 00:1F:6C:CA:7C:80
                    ESSID:"rh-wireless"
                    Mode:Master
                    Channel:9
                    Frequency:2.452 GHz (Channel 9)
                    Quality=58/100  Signal level:-73 dBm  Noise level=-127 dBm
                    Encryption key:on
                    Bit Rates:1 Mb/s; 2 Mb/s; 5.5 Mb/s; 6 Mb/s; 9 Mb/s
                              11 Mb/s; 12 Mb/s; 18 Mb/s; 24 Mb/s; 36 Mb/s
                              48 Mb/s; 54 Mb/s
                    Extra:tsf=000005c10e09e18c
                    Extra: Last beacon: 2418ms ago
          Cell 06 - Address: 00:1F:6C:CA:78:10
                    ESSID:"rh-wireless"
                    Mode:Master
                    Channel:11
                    Frequency:2.462 GHz (Channel 11)
                    Quality=76/100  Signal level:-58 dBm  Noise level=-127 dBm
                    Encryption key:on
                    Bit Rates:1 Mb/s; 2 Mb/s; 5.5 Mb/s; 6 Mb/s; 9 Mb/s
                              11 Mb/s; 12 Mb/s; 18 Mb/s; 24 Mb/s; 36 Mb/s
                              48 Mb/s; 54 Mb/s
                    Extra:tsf=000005c1121a818c
                    Extra: Last beacon: 2379ms ago
          Cell 07 - Address: 82:F2:9B:B4:2D:57
                    ESSID:"hpsetup"
                    Mode:Ad-Hoc
                    Channel:6
                    Frequency:2.437 GHz (Channel 6)
                    Quality=59/100  Signal level:-72 dBm  Noise level=-127 dBm
                    Encryption key:off
                    Bit Rates:1 Mb/s; 2 Mb/s; 5.5 Mb/s; 11 Mb/s
                    Extra:tsf=000000437fb32142
                    Extra: Last beacon: 3408ms ago

real	0m3.852s
user	0m0.001s
sys	0m0.002s

Comment 9 Christer Weinigel 2009-06-28 09:49:51 UTC
Ok, it seems that the reason for the network problems is simply that NetworkManager is performing a scan (calling nm_supplicant_interface_request_scan).  

If I start a ping in one shell and then run "iwlist wlan0 scanning", the network pauses for about 3-4 seconds and then restarts again:

64 bytes from gw.localnet (192.168.0.1): icmp_seq=3 ttl=64 time=0.902 ms
64 bytes from gw.localnet (192.168.0.1): icmp_seq=4 ttl=64 time=0.908 ms
64 bytes from gw.localnet (192.168.0.1): icmp_seq=5 ttl=64 time=0.880 ms
64 bytes from gw.localnet (192.168.0.1): icmp_seq=6 ttl=64 time=0.911 ms
64 bytes from gw.localnet (192.168.0.1): icmp_seq=7 ttl=64 time=0.903 ms
64 bytes from gw.localnet (192.168.0.1): icmp_seq=8 ttl=64 time=0.896 ms
64 bytes from gw.localnet (192.168.0.1): icmp_seq=9 ttl=64 time=3647 ms
64 bytes from gw.localnet (192.168.0.1): icmp_seq=10 ttl=64 time=2647 ms
64 bytes from gw.localnet (192.168.0.1): icmp_seq=11 ttl=64 time=1647 ms
64 bytes from gw.localnet (192.168.0.1): icmp_seq=12 ttl=64 time=647 ms
64 bytes from gw.localnet (192.168.0.1): icmp_seq=13 ttl=64 time=0.891 ms
64 bytes from gw.localnet (192.168.0.1): icmp_seq=14 ttl=64 time=0.871 ms
64 bytes from gw.localnet (192.168.0.1): icmp_seq=15 ttl=64 time=1.07 ms
64 bytes from gw.localnet (192.168.0.1): icmp_seq=16 ttl=64 time=2.78 ms

This short hiccup is enough to completely ruin the interactive performance of a ssh session and if I try to load a web page during those 3 seconds, the load gets delayed so much that I usually end up pressing reload in the web browser, and things like streaming video is just a no-no
(I some of this is due to TCP backoff which makes the perceived network outage last much longer).

I just modified request_wireless_scan so that it does not perform a scan if it is already connected to a wireless network, and this seems to fix the problem for me.  

    NMDeviceState state = nm_device_get_state (NM_DEVICE (self));

    if (can_scan (self)) {
        if (state == NM_DEVICE_STATE_CONFIG ||
            state == NM_DEVICE_STATE_NEED_AUTH ||
            state == NM_DEVICE_STATE_IP_CONFIG ||
            state == NM_DEVICE_STATE_ACTIVATED) {
            nm_debug ("%s: supressing scan, state %d", __func__, state);
            backoff = TRUE;
        } else {
            if (nm_supplicant_interface_request_scan (priv->supplicant.iface)) \
{
                /* success */
                backoff = TRUE;
            }
        }
     }

Of course, this means that I won't have an up to date AP list, but in my opinion it is _much_ better than having a network outage every other minute (a 4 second outage every 120 seconds means that the network is nonfunctional 3% of the time, and that is just terrible).

So how is the Atheros driver supposed to behave?  Is is supposed to be able to do a scan in the background without affecting network traffic, or is the outage the expected behavior?

Anyway, as long as the driver behaves as it does, I'd suggest adding a configuration option to NetworkManager to disable the periodic scan, since the periodic scan basically makes the network useless for some use cases.

Same hardware as in my previous report, a Thinkpad X40 with an Atheros card, Fedora 9, but this time with kernel 2.6.27.21-78.2.41.fc9.i686 and NetworkManager-0.7.1-1.fc9.i386.

Comment 10 Christer Weinigel 2009-06-28 10:17:04 UTC
And now when I know what's happening it's much easier to find the relevant bugs in the NetworkManager bugzilla:

http://bugzilla.gnome.org/show_bug.cgi?id=513820

There was even a workaround added for this back in 2005:

http://bugzilla.gnome.org/show_bug.cgi?id=165933

But that option is no longer present in nm-applet, so I guess it has been removed in the name of luser-friendliness or something.

Comment 11 dirkhoehne 2009-07-16 10:39:37 UTC
I'm sorry to aks these, probably naive, questions.
I have the same problem and I wanted to try the solution provided by Christer.

But where to change these lines? Do I have to create a file somewhere?

I hope, you can help me, since I have looked for this solution a long time now.

thanks

Comment 12 Ira Malinich 2009-09-12 07:52:11 UTC
I can confirm that this is affecting Fedora 11.  I'm getting the same delay every 120 seconds. I'm using an Atheros AR5001X+ a/b/g desktop card (D-Link DWL-AG530).

'lspci -v' gives me:

01:07.0 Ethernet controller: Atheros Communications Inc. Atheros AR5001X+ Wireless Network Adapter (rev 01)
        Subsystem: D-Link System Inc D-Link AirPremier DWL-AG530 Wireless PCI Adapter
        Flags: bus master, medium devsel, latency 168, IRQ 19
        Memory at fdee0000 (32-bit, non-prefetchable) [size=64K]
        Capabilities: <access denied>
        Kernel driver in use: ath5k
        Kernel modules: ath5k


I don't get any coincident messages from NetworkManager in /var/log/messages, but if I ping my gateway, every 120 seconds I get this:

(snip)
64 bytes from 10.42.43.1: icmp_seq=98 ttl=64 time=0.656 ms
64 bytes from 10.42.43.1: icmp_seq=99 ttl=64 time=0.667 ms
64 bytes from 10.42.43.1: icmp_seq=100 ttl=64 time=8076 ms
64 bytes from 10.42.43.1: icmp_seq=101 ttl=64 time=7077 ms
64 bytes from 10.42.43.1: icmp_seq=102 ttl=64 time=6074 ms
64 bytes from 10.42.43.1: icmp_seq=103 ttl=64 time=5062 ms
64 bytes from 10.42.43.1: icmp_seq=104 ttl=64 time=4050 ms
64 bytes from 10.42.43.1: icmp_seq=105 ttl=64 time=3038 ms
64 bytes from 10.42.43.1: icmp_seq=106 ttl=64 time=2027 ms
64 bytes from 10.42.43.1: icmp_seq=107 ttl=64 time=1015 ms
64 bytes from 10.42.43.1: icmp_seq=108 ttl=64 time=3.95 ms
64 bytes from 10.42.43.1: icmp_seq=109 ttl=64 time=0.696 ms
64 bytes from 10.42.43.1: icmp_seq=110 ttl=64 time=0.706 ms
(snip)


If I do 'sudo time iwlist wlan0 scan' I get a whole lot of APs and at the end:

0.00user 0.00system 0:08.82elapsed 0%CPU (0avgtext+0avgdata 0maxresident)k
0inputs+0outputs (0major+169minor)pagefaults 0swaps


I'm using kernel-2.6.30.5-43.fc11.i586 (it was also happening on the 2.6.29 series), NetworkManager-0.7.1-8.git20090708.fc11.i586, and wireless-tools-29-4.fc11.i586.

I've only recently started using my wireless card since I usually had the option of wired ethernet, so I don't know how far back this problem goes.  I can provide similar info for my Eee PC 901 and Gateway laptops, each with different b/g Realtek chipsets, if that's useful.

Comment 13 Ira Malinich 2009-09-12 22:41:26 UTC
I should clarify that these other two laptops do exhibit the same behaviour in Fedora 11, except with shorter delays of 1-3 seconds.

Comment 14 Dan Williams 2009-10-15 05:18:35 UTC
The shorter delays are likely for devices that have hardware-assisted scanning or only support 2.4GHz channels.  The 2.6.32 kernel solves this issue mainly due to the introduction of background scanning where the kernel driver will spread the scan over a longer time period but return to the active channel periodically.  Again, the real fix is in the driver and the kernel's mac80211 stack to minimize scan interruption.

Note that the disconnect/reconnect bug is fixed with kernels 2.6.29 and later which is in F10 updates for mac80211-based drivers.

The original bug reporter here has an ipw2200-based card (2915 actaully, but same driver) and thus this bug is actually a dupe of bug 478686.  The ipw2200 driver should not be disconnecting from the AP to scan.

*** This bug has been marked as a duplicate of bug 478686 ***

Comment 15 nucleo 2013-01-20 03:42:19 UTC
(In reply to comment #14)
> Again, the real fix is in the driver and the
> kernel's mac80211 stack to minimize scan interruption.

Looks like real fix still not available?
Scanning with recent kernels (3.6 and 3.7) don't interrupts connection with ath9k driver but decreasing of downloading speed still notable couple of seconds at scanning time (when running 'iw dev wlan0 scan'). Also at this time rtt shown by ping increased from 1ms to 2000ms, but no packets lost.

Comment 16 Dan Williams 2013-04-08 20:58:57 UTC
(In reply to comment #15)
> (In reply to comment #14)
> > Again, the real fix is in the driver and the
> > kernel's mac80211 stack to minimize scan interruption.
> 
> Looks like real fix still not available?
> Scanning with recent kernels (3.6 and 3.7) don't interrupts connection with
> ath9k driver but decreasing of downloading speed still notable couple of
> seconds at scanning time (when running 'iw dev wlan0 scan'). Also at this
> time rtt shown by ping increased from 1ms to 2000ms, but no packets lost.

The real fix is to lock your connection to the AP's BSSID if you do not want autoscanning behavior.

Comment 17 nucleo 2013-04-08 21:03:49 UTC
(In reply to comment #16)
> The real fix is to lock your connection to the AP's BSSID if you do not want
> autoscanning behavior.

I already did this, but I think that real fix is make autoscanning not affecting on established connection such as increased to 3000ms delays.


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