Bug 556647 - Wireless connection looses conectivity immediately after assoc and dhcpclient
Summary: Wireless connection looses conectivity immediately after assoc and dhcpclient
Keywords:
Status: CLOSED CANTFIX
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 12
Hardware: All
OS: Linux
high
high
Target Milestone: ---
Assignee: Kernel Maintainer List
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2010-01-18 23:50 UTC by Bogdan Dumitrache
Modified: 2010-09-09 08:23 UTC (History)
14 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2010-09-09 08:23:00 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)

Description Bogdan Dumitrache 2010-01-18 23:50:45 UTC
Description of problem:


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

stock version from dvd iso or latest update


How reproducible:
Every time

Steps to Reproduce:
1.Install FC12
2.Test
3.Update FC12
4.Test
  
Actual results:
The wireless connection drops in ~1min after association

Expected results:
Should have a dependable connection

Additional info:

Toshiba A300 notebook,

00:00.0 Host bridge: Intel Corporation Mobile PM965/GM965/GL960 Memory Controller Hub (rev 03)
00:01.0 PCI bridge: Intel Corporation Mobile PM965/GM965/GL960 PCI Express Root Port (rev 03)
00:1a.0 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #4 (rev 03)
00:1a.1 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #5 (rev 03)
00:1a.7 USB Controller: Intel Corporation 82801H (ICH8 Family) USB2 EHCI Controller #2 (rev 03)
00:1b.0 Audio device: Intel Corporation 82801H (ICH8 Family) HD Audio Controller (rev 03)
00:1c.0 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 1 (rev 03)
00:1c.1 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 2 (rev 03)
00:1c.4 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 5 (rev 03)
00:1d.0 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #1 (rev 03)
00:1d.1 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #2 (rev 03)
00:1d.2 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI Controller #3 (rev 03)
00:1d.7 USB Controller: Intel Corporation 82801H (ICH8 Family) USB2 EHCI Controller #1 (rev 03)
00:1e.0 PCI bridge: Intel Corporation 82801 Mobile PCI Bridge (rev f3)
00:1f.0 ISA bridge: Intel Corporation 82801HEM (ICH8M) LPC Interface Controller (rev 03)
00:1f.1 IDE interface: Intel Corporation 82801HBM/HEM (ICH8M/ICH8M-E) IDE Controller (rev 03)
00:1f.2 SATA controller: Intel Corporation 82801HBM/HEM (ICH8M/ICH8M-E) SATA AHCI Controller (rev 03)
00:1f.3 SMBus: Intel Corporation 82801H (ICH8 Family) SMBus Controller (rev 03)
01:00.0 VGA compatible controller: ATI Technologies Inc Mobility Radeon HD 3400 Series
02:00.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL8101E/RTL8102E PCI Express Fast Ethernet controller (rev 02)
03:00.0 Network controller: Intel Corporation PRO/Wireless 3945ABG [Golan] Network Connection (rev 02)
06:06.0 FireWire (IEEE 1394): Ricoh Co Ltd R5C832 IEEE 1394 Controller (rev 05)
06:06.1 SD Host controller: Ricoh Co Ltd R5C822 SD/SDIO/MMC/MS/MSPro Host Adapter (rev 22)
06:06.2 System peripheral: Ricoh Co Ltd R5C592 Memory Stick Bus Host Adapter (rev 12)
06:06.3 System peripheral: Ricoh Co Ltd xD-Picture Card Controller (rev 12)

Comment 1 Dan Williams 2010-01-27 20:47:08 UTC
Can you grab /var/log/messages when you see this problem appearing?

Comment 2 Bogdan Dumitrache 2010-02-09 09:17:41 UTC
Now I have fedora 10 installed because my laptop is highly productive :) and the following releases do not give me the stability required for a production environment even if it is only a desktop (no wireless, video artifacts etc)
Nevertheless from what I saw when I had FC12 installed, NM was trying to refresh the list of nearby wireless AP's and then it lost its connectivity. Strange enough (but I suspect it had something to do also with my AP) it didn't reconnect.

Comment 3 Bogdan Dumitrache 2010-02-17 23:32:35 UTC
NetworkManager: <info> Activation (wlan0) starting connection 'MSI'                                                                                                                 
NetworkManager: <info> (wlan0): device state change: 3 -> 4 (reason 0)                                                                                                              
NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...                                                                                                
NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...                                                                                                  
NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...                                                                                              
NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.                                                                                                   
NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...                                                                                               
NetworkManager: <info> (wlan0): device state change: 4 -> 5 (reason 0)                                                                                                              
NetworkManager: <info> Activation (wlan0/wireless): access point 'MSI' has security, but secrets are required.                                                                      
NetworkManager: <info> (wlan0): device state change: 5 -> 6 (reason 0)                                                                                                              
NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.                                                                                                 
NetworkManager: <WARN> secrets_update_setting(): Failed to update connection secrets: 1 802-1x                                                                                      
NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...                                                                                                
NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...                                                                                                  
NetworkManager: <info> (wlan0): device state change: 6 -> 4 (reason 0)                                                                                                              
NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...                                                                                              
NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.                                                                                                   
NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...                                                                                               
NetworkManager: <info> (wlan0): device state change: 4 -> 5 (reason 0)                                                                                                              
NetworkManager: <info> Activation (wlan0/wireless): connection 'MSI' has security, and secrets exist. No new secrets needed.                                                        
NetworkManager: <info> Config: added 'ssid' value 'MSI'                                                                                                                             
NetworkManager: <info> Config: added 'scan_ssid' value '1'                                                                                                                          
NetworkManager: <info> Config: added 'key_mgmt' value 'WPA-PSK'                                                                                                                     
NetworkManager: <info> Config: added 'psk' value '<omitted>'                                                                                                                        
NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.                                                                                                 
NetworkManager: <info> Config: set interface ap_scan to 1
NetworkManager: <info> (wlan0): supplicant connection state: scanning -> disconnected
NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> associating
NetworkManager: <info> (wlan0): supplicant connection state: associating -> associated
NetworkManager: <info> (wlan0): supplicant connection state: associated -> 4-way handshake
NetworkManager: <info> (wlan0): supplicant connection state: 4-way handshake -> group handshake
NetworkManager: <info> (wlan0): supplicant connection state: group handshake -> completed
NetworkManager: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'MSI'.
NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.                        
NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...                                                                                              
NetworkManager: <info> (wlan0): device state change: 5 -> 7 (reason 0)                                                                                                              
NetworkManager: Activation (wlan0) Beginning DHCPv4 transaction (timeout in 45 seconds)                                                                                             
NetworkManager: <info> dhclient started with pid 18761                                                                                                                              
NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP6 Configure Get) scheduled...                                                                                             
NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.                                                                                               
NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP6 Configure Get) started...                                                                                               
NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP6 Configure Get) complete.                                                                                                
dhclient[18761]: Internet Systems Consortium DHCP Client 4.1.1                                                                                                                      
dhclient[18761]: Copyright 2004-2010 Internet Systems Consortium.                                                                                                                   
dhclient[18761]: All rights reserved.                                                                                                                                               
dhclient[18761]: For info, please visit https://www.isc.org/software/dhcp/                                                                                                          
dhclient[18761]:                                                                                                                                                                    
NetworkManager: DHCPv4: device wlan0 state changed nbi -> preinit                                                                                                                   
dhclient[18761]: Listening on LPF/wlan0/00:1f:3c:96:b8:bb                                                                                                                           
dhclient[18761]: Sending on LPF/wlan0/00:1f:3c:96:b8:bb                                                                                                                             
dhclient[18761]: Sending on Socket/fallback                                                                                                                                         
dhclient[18761]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 4                                                                                                        
dhclient[18761]: DHCPOFFER from 192.168.111.254                                                                                                                                     
dhclient[18761]: DHCPREQUEST on wlan0 to 255.255.255.255 port 67                                                                                                                    
dhclient[18761]: DHCPACK from 192.168.111.254                                                                                                                                       
NetworkManager: DHCPv4: device wlan0 state changed preinit -> bound                                                                                                                 
NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) scheduled...                                                                                             
NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) started...                                                                                               
NetworkManager: address 192.168.111.100                                                                                                                                             
NetworkManager: prefix 24 (255.255.255.0)                                                                                                                                           
NetworkManager: gateway 192.168.111.254                                                                                                                                             
NetworkManager: nameserver '193.239.140.12'                                                                                                                                         
NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) scheduled...                                                                                           
NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) complete.                                                                                                
NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started...                                                                                             
dhclient[18761]: bound to 192.168.111.100 -- renewal in 403790 seconds.                                                                                                             
NetworkManager: <info> (wlan0): device state change: 7 -> 8 (reason 0)                                                                                                              
NetworkManager: <info> Policy set 'MSI' (wlan0) as default for routing and DNS.                                                                                                     
NetworkManager: <info> Activation (wlan0) successful, device activated.                                                                                                             
NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complete.                                                                                              
NetworkManager: <info> (wlan0): supplicant connection state: completed -> disconnected                                                                                              
NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning                                                                                               
NetworkManager: <info> (wlan0): supplicant connection state: scanning -> associating                                                                                                
NetworkManager: <info> (wlan0): device state change: 8 -> 3 (reason 11)                                                                                                             
NetworkManager: <info> (wlan0): deactivating device (reason: 11).                                                                                                                   
NetworkManager: (wlan0): canceled DHCP transaction, dhcp client pid 18761                                                                                                           
NetworkManager: <WARN> check_one_route(): (wlan0) error -34 returned from rtnl_route_del(): Sucess#012                                                                              
NetworkManager: <info> Activation (wlan0) starting connection 'MSI'                                                                                                                 
NetworkManager: <info> (wlan0): device state change: 3 -> 4 (reason 0)                                                                                                              
NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...                                                                                                
NetworkManager: <info> (wlan0): supplicant connection state: associating -> disconnected                                                                                            
NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...                                                                                                  
NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...                                                                                              
NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.                                                                                                   
NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...                                                                                               
NetworkManager: <info> (wlan0): device state change: 4 -> 5 (reason 0)                                                                                                              
NetworkManager: <info> Activation (wlan0/wireless): access point 'MSI' has security, but secrets are required.                                                                      
NetworkManager: <info> (wlan0): device state change: 5 -> 6 (reason 0)                                                                                                              
NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.                                                                                                 
NetworkManager: <WARN> secrets_update_setting(): Failed to update connection secrets: 1 802-1x                                                                                      
NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...                                                                                                
NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...                                                                                                  
NetworkManager: <info> (wlan0): device state change: 6 -> 4 (reason 0)                                                                                                              
NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...                                                                                              
NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.                                                                                                   
NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...                                                                                               
NetworkManager: <info> (wlan0): device state change: 4 -> 5 (reason 0)                                                                                                              
NetworkManager: <info> Activation (wlan0/wireless): connection 'MSI' has security, and secrets exist. No new secrets needed.                                                        
NetworkManager: <info> Config: added 'ssid' value 'MSI'                                                                                                                             
NetworkManager: <info> Config: added 'scan_ssid' value '1'                                                                                                                          
NetworkManager: <info> Config: added 'key_mgmt' value 'WPA-PSK'                                                                                                                     
NetworkManager: <info> Config: added 'psk' value '<omitted>'                                                                                                                        
NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.                                                                                                 
NetworkManager: <info> Config: set interface ap_scan to 1                                                                                                                           
NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning                                                                                               
NetworkManager: <info> (wlan0): supplicant connection state: scanning -> associating                                                                                                
NetworkManager: <info> (wlan0): supplicant connection state: associating -> disconnected                                                                                            
NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning                                                                                               
NetworkManager: <info> (wlan0): supplicant connection state: scanning -> associating                                                                                                
NetworkManager: <info> Activation (wlan0/wireless): association took too long.                                                                                                      
NetworkManager: <info> (wlan0): device state change: 5 -> 6 (reason 0)                                                                                                              
NetworkManager: <info> Activation (wlan0/wireless): asking for new secrets                                                                                                          
NetworkManager: <info> (wlan0): supplicant connection state: associating -> disconnected                                                                                            
NetworkManager: <info> (wlan0): device state change: 6 -> 9 (reason 7)                                                                                                              
NetworkManager: <info> Activation (wlan0) failed for access point (MSI)                                                                                                             
NetworkManager: <info> Marking connection 'MSI' invalid.                                                                                                                            
NetworkManager: <info> Activation (wlan0) failed.                                                                                                                                   
NetworkManager: <info> (wlan0): device state change: 9 -> 3 (reason 0)                                                                                                              
NetworkManager: <info> (wlan0): deactivating device (reason: 0).

Comment 4 Bogdan Dumitrache 2010-02-17 23:33:42 UTC
Oh and one more very important thing...
I think it only has to do with WPA and not with WPA2, I will check again tomorrow.

Comment 5 Bogdan Dumitrache 2010-02-17 23:54:06 UTC
Yes, I can confirm it. After changing my AP to WEP2 the problem dissapeared.

Comment 6 Steven M. Parrish 2010-04-13 16:20:09 UTC
This just started happening for me on F12, using both a WAP2 connection and bluetooth connection to my phone.

Here is my log

Apr 13 12:07:42 localhost NetworkManager: <info> (wlan0): supplicant connection state:  completed -> group handshake
Apr 13 12:07:42 localhost NetworkManager: <info> (wlan0): supplicant connection state:  group handshake -> completed
Apr 13 12:08:13 localhost NetworkManager: <info> (wlan0): supplicant connection state:  completed -> group handshake
Apr 13 12:08:13 localhost NetworkManager: <info> (wlan0): supplicant connection state:  group handshake -> completed
Apr 13 12:08:18 localhost NetworkManager: <info> (wlan0): supplicant connection state:  completed -> group handshake
Apr 13 12:08:18 localhost NetworkManager: <info> (wlan0): supplicant connection state:  group handshake -> completed
Apr 13 12:08:23 localhost NetworkManager: <info> (wlan0): supplicant connection state:  completed -> group handshake
Apr 13 12:08:23 localhost NetworkManager: <info> (wlan0): supplicant connection state:  group handshake -> completed
Apr 13 12:08:28 localhost NetworkManager: <info> (wlan0): supplicant connection state:  completed -> group handshake
Apr 13 12:08:28 localhost NetworkManager: <info> (wlan0): supplicant connection state:  group handshake -> completed
Apr 13 12:08:33 localhost NetworkManager: <info> (wlan0): supplicant connection state:  completed -> disconnected
Apr 13 12:08:33 localhost NetworkManager: <info> (wlan0): supplicant connection state:  disconnected -> scanning
Apr 13 12:08:34 localhost NetworkManager: <info> (wlan0): supplicant connection state:  scanning -> associating
Apr 13 12:08:40 localhost NetworkManager: <info> (wlan0): roamed from BSSID 00:22:75:93:DE:8F (TuxWorld) to (none) ((none))
Apr 13 12:08:49 localhost NetworkManager: <info> (wlan0): device state change: 8 -> 3 (reason 11)
Apr 13 12:08:49 localhost NetworkManager: <info> (wlan0): deactivating device (reason: 11).
Apr 13 12:08:49 localhost NetworkManager: <info> (wlan0): canceled DHCP transaction, DHCP client pid 9539
Apr 13 12:08:49 localhost avahi-daemon[1327]: Withdrawing address record for 192.168.2.5 on wlan0.
Apr 13 12:08:49 localhost avahi-daemon[1327]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.5.
Apr 13 12:08:49 localhost avahi-daemon[1327]: Interface wlan0.IPv4 no longer relevant for mDNS.
Apr 13 12:08:49 localhost NetworkManager: <info> Activation (wlan0) starting connection 'Auto TuxWorld'
Apr 13 12:08:49 localhost NetworkManager: <info> (wlan0): device state change: 3 -> 4 (reason 0)
Apr 13 12:08:49 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Apr 13 12:08:49 localhost NetworkManager: <info> (wlan0): supplicant connection state:  associating -> disconnected
Apr 13 12:08:49 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Apr 13 12:08:49 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Apr 13 12:08:49 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Apr 13 12:08:49 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Apr 13 12:08:49 localhost NetworkManager: <info> (wlan0): device state change: 4 -> 5 (reason 0)
Apr 13 12:08:49 localhost NetworkManager: <info> Activation (wlan0/wireless): access point 'Auto TuxWorld' has security, but secrets are required.
Apr 13 12:08:49 localhost NetworkManager: <info> (wlan0): device state change: 5 -> 6 (reason 0)
Apr 13 12:08:49 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Apr 13 12:08:49 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Apr 13 12:08:49 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Apr 13 12:08:49 localhost NetworkManager: <info> (wlan0): device state change: 6 -> 4 (reason 0)
Apr 13 12:08:49 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Apr 13 12:08:49 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Apr 13 12:08:49 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Apr 13 12:08:49 localhost NetworkManager: <info> (wlan0): device state change: 4 -> 5 (reason 0)
Apr 13 12:08:49 localhost NetworkManager: <info> Activation (wlan0/wireless): connection 'Auto TuxWorld' has security, and secrets exist.  No new secrets needed.
Apr 13 12:08:49 localhost NetworkManager: <info> Config: added 'ssid' value 'TuxWorld'
Apr 13 12:08:49 localhost NetworkManager: <info> Config: added 'scan_ssid' value '1'
Apr 13 12:08:49 localhost NetworkManager: <info> Config: added 'key_mgmt' value 'WPA-PSK'
Apr 13 12:08:49 localhost NetworkManager: <info> Config: added 'psk' value '<omitted>'
Apr 13 12:08:49 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Apr 13 12:08:49 localhost NetworkManager: <info> Config: set interface ap_scan to 1
Apr 13 12:08:49 localhost NetworkManager: <info> (wlan0): supplicant connection state:  disconnected -> scanning
Apr 13 12:08:50 localhost ntpd[1618]: Deleting interface #43 wlan0, 192.168.2.5#123, interface stats: received=16, sent=18, dropped=0, active_time=389 secs
Apr 13 12:08:50 localhost NetworkManager: <info> (wlan0): supplicant connection state:  scanning -> associating
Apr 13 12:09:10 localhost NetworkManager: <info> (wlan0): supplicant connection state:  associating -> disconnected
Apr 13 12:09:10 localhost NetworkManager: <info> (wlan0): supplicant connection state:  disconnected -> scanning
Apr 13 12:09:11 localhost NetworkManager: <info> (wlan0): supplicant connection state:  scanning -> associating
Apr 13 12:09:14 localhost NetworkManager: <info> caught signal 15, shutting down normally.
Apr 13 12:09:14 localhost NetworkManager: <info> (wlan0): deactivating device (reason: 36).
Apr 13 12:09:14 localhost NetworkManager: <info> (wlan0): taking down device.
Apr 13 12:09:14 localhost avahi-daemon[1327]: Withdrawing address record for fe80::21a:73ff:fe11:e3e9 on wlan0.
Apr 13 12:09:14 localhost NetworkManager: <info> (eth0): cleaning up...
Apr 13 12:09:14 localhost NetworkManager: <info> (eth0): taking down device.
Apr 13 12:09:14 localhost NetworkManager: <info> exiting (success)
Apr 13 12:09:15 localhost NetworkManager: <info> starting...
Apr 13 12:09:15 localhost NetworkManager: <info> modem-manager is now available
Apr 13 12:09:16 localhost NetworkManager:    ifcfg-rh: Acquired D-Bus service com.redhat.ifcfgrh1
Apr 13 12:09:16 localhost NetworkManager: <info> Loaded plugin ifcfg-rh: (c) 2007 - 2008 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
Apr 13 12:09:16 localhost NetworkManager: <info> found WiFi radio killswitch rfkill2 (at /sys/devices/pci0000:00/0000:00:03.0/0000:03:00.0/ssb0:0/ieee80211/phy0/rfkill2) (driver <unknown>)
Apr 13 12:09:16 localhost NetworkManager: <info> found WiFi radio killswitch rfkill0 (at /sys/devices/platform/hp-wmi/rfkill/rfkill0) (driver hp-wmi)
Apr 13 12:09:16 localhost NetworkManager: <info> WiFi enabled by radio killswitch; enabled by state file
Apr 13 12:09:16 localhost NetworkManager: <info> WWAN enabled by radio killswitch; enabled by state file
Apr 13 12:09:16 localhost NetworkManager: <info> WiMAX enabled by radio killswitch; enabled by state file
Apr 13 12:09:16 localhost NetworkManager: <info> Networking is enabled by state file
Apr 13 12:09:16 localhost NetworkManager:    ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-bnep0 ... 
Apr 13 12:09:16 localhost NetworkManager:    ifcfg-rh:     read connection 'System bnep0'
Apr 13 12:09:16 localhost NetworkManager:    ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-lo ... 
Apr 13 12:09:16 localhost NetworkManager:    ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-wlan0 ... 
Apr 13 12:09:16 localhost NetworkManager:    ifcfg-rh:     error: Missing SSID
Apr 13 12:09:16 localhost NetworkManager:    ifcfg-rh: parsing /etc/sysconfig/network-scripts/ifcfg-eth0 ... 
Apr 13 12:09:16 localhost NetworkManager:    ifcfg-rh:     read connection 'System eth0'
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): driver supports SSID scans (scan_capa 0x01).
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): new 802.11 WiFi device (driver: 'b43')
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): exported as /org/freedesktop/NetworkManager/Devices/0
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): now managed
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): device state change: 1 -> 2 (reason 2)
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): bringing up device.
Apr 13 12:09:16 localhost kernel: b43 ssb0:0: firmware: requesting b43/pcm5.fw
Apr 13 12:09:16 localhost firmware.sh[9691]: Cannot find  firmware file 'b43/pcm5.fw'
Apr 13 12:09:16 localhost kernel: b43-phy0: Loading OpenSource firmware version 410.31754
Apr 13 12:09:16 localhost kernel: b43-phy0: Hardware crypto acceleration not supported by firmware
Apr 13 12:09:16 localhost kernel: b43-phy0: QoS not supported by firmware
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): preparing device.
Apr 13 12:09:16 localhost kernel: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): deactivating device (reason: 2).
Apr 13 12:09:16 localhost NetworkManager: <info> (eth0): carrier is OFF
Apr 13 12:09:16 localhost NetworkManager: <info> (eth0): new Ethernet device (driver: 'forcedeth')
Apr 13 12:09:16 localhost NetworkManager: <info> (eth0): exported as /org/freedesktop/NetworkManager/Devices/1
Apr 13 12:09:16 localhost NetworkManager: <info> (eth0): now managed
Apr 13 12:09:16 localhost NetworkManager: <info> (eth0): device state change: 1 -> 2 (reason 2)
Apr 13 12:09:16 localhost NetworkManager: <info> (eth0): bringing up device.
Apr 13 12:09:16 localhost kernel: eth0: no link during initialization.
Apr 13 12:09:16 localhost NetworkManager: <info> (eth0): preparing device.
Apr 13 12:09:16 localhost NetworkManager: <info> (eth0): deactivating device (reason: 2).
Apr 13 12:09:16 localhost kernel: ADDRCONF(NETDEV_UP): eth0: link is not ready
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): supplicant interface state:  starting -> ready
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): device state change: 2 -> 3 (reason 42)
Apr 13 12:09:16 localhost ntpd[1618]: Deleting interface #42 wlan0, fe80::21a:73ff:fe11:e3e9#123, interface stats: received=0, sent=0, dropped=0, active_time=430 secs
Apr 13 12:09:16 localhost NetworkManager: <info> Activation (wlan0) starting connection 'Auto TuxWorld'
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): device state change: 3 -> 4 (reason 0)
Apr 13 12:09:16 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Apr 13 12:09:16 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Apr 13 12:09:16 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Apr 13 12:09:16 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Apr 13 12:09:16 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): device state change: 4 -> 5 (reason 0)
Apr 13 12:09:16 localhost NetworkManager: <info> Activation (wlan0/wireless): access point 'Auto TuxWorld' has security, but secrets are required.
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): device state change: 5 -> 6 (reason 0)
Apr 13 12:09:16 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Apr 13 12:09:16 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Apr 13 12:09:16 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): device state change: 6 -> 4 (reason 0)
Apr 13 12:09:16 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Apr 13 12:09:16 localhost NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Apr 13 12:09:16 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): device state change: 4 -> 5 (reason 0)
Apr 13 12:09:16 localhost NetworkManager: <info> Activation (wlan0/wireless): connection 'Auto TuxWorld' has security, and secrets exist.  No new secrets needed.
Apr 13 12:09:16 localhost NetworkManager: <info> Config: added 'ssid' value 'TuxWorld'
Apr 13 12:09:16 localhost NetworkManager: <info> Config: added 'scan_ssid' value '1'
Apr 13 12:09:16 localhost NetworkManager: <info> Config: added 'key_mgmt' value 'WPA-PSK'
Apr 13 12:09:16 localhost NetworkManager: <info> Config: added 'psk' value '<omitted>'
Apr 13 12:09:16 localhost NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Apr 13 12:09:16 localhost NetworkManager: <info> Config: set interface ap_scan to 1
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): supplicant connection state:  scanning -> disconnected
Apr 13 12:09:16 localhost NetworkManager: <info> (wlan0): supplicant connection state:  disconnected -> associating
Apr 13 12:09:17 localhost kernel: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Apr 13 12:09:17 localhost NetworkManager: <info> (wlan0): supplicant connection state:  associating -> associated
Apr 13 12:09:18 localhost avahi-daemon[1327]: Registering new address record for fe80::21a:73ff:fe11:e3e9 on wlan0.*.
Apr 13 12:09:19 localhost NetworkManager: <info> (wlan0): supplicant connection state:  associated -> 4-way handshake
Apr 13 12:09:19 localhost NetworkManager: <info> (wlan0): supplicant connection state:  4-way handshake -> group handshake
Apr 13 12:09:19 localhost NetworkManager: <info> (wlan0): supplicant connection state:  group handshake -> completed
Apr 13 12:09:19 localhost NetworkManager: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network 'TuxWorld'.
Apr 13 12:09:19 localhost NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.
Apr 13 12:09:19 localhost NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...
Apr 13 12:09:19 localhost NetworkManager: <info> (wlan0): device state change: 5 -> 7 (reason 0)
Apr 13 12:09:19 localhost NetworkManager: <info> Activation (wlan0) Beginning DHCPv4 transaction (timeout in 45 seconds)
Apr 13 12:09:19 localhost NetworkManager: <info> dhclient started with pid 9706
Apr 13 12:09:19 localhost NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP6 Configure Get) scheduled...
Apr 13 12:09:19 localhost NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.
Apr 13 12:09:19 localhost NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP6 Configure Get) started...
Apr 13 12:09:19 localhost NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP6 Configure Get) complete.
Apr 13 12:09:19 localhost dhclient[9706]: Internet Systems Consortium DHCP Client 4.1.1
Apr 13 12:09:19 localhost dhclient[9706]: Copyright 2004-2010 Internet Systems Consortium.
Apr 13 12:09:19 localhost dhclient[9706]: All rights reserved.
Apr 13 12:09:19 localhost dhclient[9706]: For info, please visit https://www.isc.org/software/dhcp/
Apr 13 12:09:19 localhost dhclient[9706]: 
Apr 13 12:09:19 localhost dhclient[9706]: Listening on LPF/wlan0/00:1a:73:11:e3:e9
Apr 13 12:09:19 localhost dhclient[9706]: Sending on   LPF/wlan0/00:1a:73:11:e3:e9
Apr 13 12:09:19 localhost dhclient[9706]: Sending on   Socket/fallback
Apr 13 12:09:19 localhost NetworkManager: <info> (wlan0): DHCPv4 state changed nbi -> preinit
Apr 13 12:09:20 localhost ntpd[1618]: Listening on interface #44 wlan0, fe80::21a:73ff:fe11:e3e9#123 Enabled
Apr 13 12:09:21 localhost dhclient[9706]: DHCPREQUEST on wlan0 to 255.255.255.255 port 67
Apr 13 12:09:28 localhost dhclient[9706]: DHCPREQUEST on wlan0 to 255.255.255.255 port 67
Apr 13 12:09:28 localhost dhclient[9706]: DHCPACK from 192.168.2.1
Apr 13 12:09:28 localhost dhclient[9706]: bound to 192.168.2.5 -- renewal in 2147483648 seconds.
Apr 13 12:09:28 localhost NetworkManager: <info> (wlan0): DHCPv4 state changed preinit -> reboot
Apr 13 12:09:28 localhost NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) scheduled...
Apr 13 12:09:28 localhost NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) started...
Apr 13 12:09:28 localhost NetworkManager: <info>   address 192.168.2.5
Apr 13 12:09:28 localhost NetworkManager: <info>   prefix 24 (255.255.255.0)
Apr 13 12:09:28 localhost NetworkManager: <info>   gateway 192.168.2.1
Apr 13 12:09:28 localhost NetworkManager: <info>   nameserver '192.168.2.1'
Apr 13 12:09:28 localhost NetworkManager: <info>   domain name 'TuxWorld'
Apr 13 12:09:28 localhost NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) scheduled...
Apr 13 12:09:28 localhost NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) complete.
Apr 13 12:09:28 localhost NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started...
Apr 13 12:09:28 localhost avahi-daemon[1327]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.2.5.
Apr 13 12:09:28 localhost avahi-daemon[1327]: New relevant interface wlan0.IPv4 for mDNS.
Apr 13 12:09:28 localhost avahi-daemon[1327]: Registering new address record for 192.168.2.5 on wlan0.IPv4.
Apr 13 12:09:29 localhost NetworkManager: <info> (wlan0): device state change: 7 -> 8 (reason 0)
Apr 13 12:09:29 localhost NetworkManager: <info> Policy set 'Auto TuxWorld' (wlan0) as default for routing and DNS.
Apr 13 12:09:29 localhost NetworkManager: <info> Activation (wlan0) successful, device activated.
Apr 13 12:09:29 localhost NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complete.
Apr 13 12:09:29 localhost ntpd[1618]: Listening on interface #45 wlan0, 192.168.2.5#123 Enabled


This just started with the upgrade to NetworkManager 0.8

Comment 7 Jirka Klimes 2010-04-16 08:33:04 UTC
As a wireless issue, wpa_supplicant logs would be useful.

Can you follow the directions in the "Debugging WiFi Connections" section?

http://live.gnome.org/NetworkManager/Debugging

and provide wpa_supplicant -dddt logs.

Thanks.

Comment 8 Harry Smith 2010-04-23 17:53:55 UTC
Ok, I am having a similar problem as above. 

If I boot with the  2.6.32.11-99.fc12.i686.PAE  the system stalls.  I receive the IP address then dead but does not disconnect. 

If I boot with the 2.6.31.5-127.fc12.i686.PAE kernel everything works fine.  I
am using an AirLink 101 PCMCIA which is a straight G card and a Linksys WRT54GL
Firmware Version: v4.30.11.  Wireless security is set to wpa2-psk, aes, group
rekey 3600. 

This is sounds similar to Bug 503983  that was closed.

Comment 9 Dan Williams 2010-04-23 20:12:14 UTC
Note that logs like this:

Apr 13 12:08:33 localhost NetworkManager: <info> (wlan0): supplicant connection
state:  completed -> disconnected
Apr 13 12:08:33 localhost NetworkManager: <info> (wlan0): supplicant connection
state:  disconnected -> scanning
Apr 13 12:08:34 localhost NetworkManager: <info> (wlan0): supplicant connection
state:  scanning -> associating
Apr 13 12:08:40 localhost NetworkManager: <info> (wlan0): roamed from BSSID
00:22:75:93:DE:8F (TuxWorld) to (none) ((none))
Apr 13 12:08:49 localhost NetworkManager: <info> (wlan0): device state change:
8 -> 3 (reason 11)

indicate driver problems as the driver was not able to reassociate with the access point after being dropped somehow.

Given comment #8 I'm going to punt this to kernel.

What wifi hard does everyone have?  What kernel version are you running?

Comment 10 sergeobelare 2010-05-08 19:28:29 UTC
This sounds very much like the problem I have.
I have a Broadcom 4311 card, latest stable wireless but it doesn't seem to matter.
2.6.32.11-99.fc12.i686

Successful reconnection always involves flipping the wireless switch off and on briefly.

Comment 11 sergeobelare 2010-05-11 06:20:18 UTC
The constant dissociation makes wireless very difficult. I've discovered that I can also recover by doing (in NetworkManager) disconnect, disable wireless, enable, connect. This save wear and tear on my wireless switch :-) A minute or two later I have to do it again.

I can do more detail troubleshooting, but where? This bug seems to be dying.

Comment 12 sergeobelare 2010-05-14 11:37:15 UTC
Are we holding off on this in lieu of FC13?

FYI, my sequence seems to be that the client disassociates for inactivity, tries to reauthenticate, authentication times out, perhaps because the AP thinks its already authenticated. Then repeated scan, auth timeout, fail to connect. When I disconnect / disable / enable / connect, then I see deauth 00:14:a5:eb:7d:79 -> 00:1c:f0:b8:7d:f1 reason 3: Deauthenticated because sending station is leaving (or has left.); then it will successfully reconnect.

Comment 13 Michel Ludwig 2010-06-19 16:26:08 UTC
I now experience the same problems as described in comments 11 and 12 on FC13. The module in question is iwl3945 and the kernel version is 2.6.33.5-124.fc13.x86_64.

Comment 14 Stanislaw Gruszka 2010-09-09 08:23:00 UTC
We have 3 different drivers in that bug report: AirLink, Broadcom and Intel. Please open separate bug reports for each of them using kernel as component. Please assign opened Intel wireless driver bugs to me.


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