Bug 795189

Summary: Activation (wlan0/wireless): association took too long, failing activation.
Product: [Fedora] Fedora Reporter: Wendell Baker <wendellcraigbaker>
Component: iwl3945-firmwareAssignee: Matthias Saou <matthias>
Status: CLOSED WONTFIX QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 16CC: matthias, wielkipiec
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-02-13 16:32:58 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Wendell Baker 2012-02-19 23:47:09 UTC
Description of problem:

Intel wireless won't associate with an open network

The hardware is
Intel Corporation PRO/Wireless 3945ABG [Golan] Network Connection (rev 02)

This seems to have been covered in
https://bugzilla.redhat.com/show_bug.cgi?id=487687
but was inconclusive.

This case
a) has no security on the wifi network
b) is not a "hidden" network

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

NetworkManager-0.9.2-1.fc16.i686
wireless-tools-29-6.1.fc15.i686
wpa_supplicant-0.7.3-11.fc16.i686

How reproducible:

is deterministic

Steps to Reproduce:
1. sudo /sbin/ifup wlan0

I am not on an interactive desktop.
I have ssh'ed into the box.

Actual results:

$ sudo /sbin/ifup wlan0
Active connection state: activating
Active connection path: /org/freedesktop/NetworkManager/ActiveConnection/15

** (process:6088): WARNING **: _nm_object_get_property: Error getting 'State' for /org/freedesktop/NetworkManager/ActiveConnection/15: (19) Method "Get" with signature "ss" on interface "org.freedesktop.DBus.Properties" doesn't exist


state: unknown
Error: Connection activation failed.

(the output in /var/log/messages is shown below)



Expected results:

wlan0 associates and receives an IPv4 from dhcp as it does with atheros and other intel wifi chips.

Additional info:

$ cat /etc/sysconfig/network-scripts/ifcfg-wlan0 
DEVICE="wlan0"
HWADDR="00:19:D2:9b:01:09"
BOOTPROTO="dhcp"
ONBOOT="yes"
NM_CONTROLLED="yes"
ESSID='acedia'
# this interface should not modify /etc/resolv.conf
PEERDNS=no
# this interface should not modify /etc/resolv.conf
RESOLV_MODS=no


$ uname -a
Linux hippie 3.2.3-2.fc16.i686.PAE #1 SMP Fri Feb 3 19:57:53 UTC 2012 i686 i686 i386 GNU/Linux

$ cat /etc/fedora-release 
Fedora release 16 (Verne)

$ sudo yum update -y
Loaded plugins: langpacks, presto, refresh-packagekit
Setting up Update Process
No Packages marked for Update


$ /sbin/lsmod | grep iw
iwl3945                55278  0 
iwlegacy               59610  1 iwl3945
mac80211              380494  2 iwl3945,iwlegacy
cfg80211              164741  3 iwl3945,iwlegacy,mac80211

$ /sbin/lspci
00:00.0 Host bridge: Intel Corporation Mobile 945GM/PM/GMS, 943/940GML and 945GT Express Memory Controller Hub (rev 03)
00:02.0 VGA compatible controller: Intel Corporation Mobile 945GM/GMS, 943/940GML Express Integrated Graphics Controller (rev 03)
00:02.1 Display controller: Intel Corporation Mobile 945GM/GMS/GME, 943/940GML Express Integrated Graphics Controller (rev 03)
00:1b.0 Audio device: Intel Corporation N10/ICH 7 Family High Definition Audio Controller (rev 02)
00:1c.0 PCI bridge: Intel Corporation N10/ICH 7 Family PCI Express Port 1 (rev 02)
00:1c.1 PCI bridge: Intel Corporation N10/ICH 7 Family PCI Express Port 2 (rev 02)
00:1c.2 PCI bridge: Intel Corporation N10/ICH 7 Family PCI Express Port 3 (rev 02)
00:1d.0 USB Controller: Intel Corporation N10/ICH 7 Family USB UHCI Controller #1 (rev 02)
00:1d.1 USB Controller: Intel Corporation N10/ICH 7 Family USB UHCI Controller #2 (rev 02)
00:1d.2 USB Controller: Intel Corporation N10/ICH 7 Family USB UHCI Controller #3 (rev 02)
00:1d.3 USB Controller: Intel Corporation N10/ICH 7 Family USB UHCI Controller #4 (rev 02)
00:1d.7 USB Controller: Intel Corporation N10/ICH 7 Family USB2 EHCI Controller (rev 02)
00:1e.0 PCI bridge: Intel Corporation 82801 Mobile PCI Bridge (rev e2)
00:1f.0 ISA bridge: Intel Corporation 82801GBM (ICH7-M) LPC Interface Bridge (rev 02)
00:1f.1 IDE interface: Intel Corporation 82801G (ICH7 Family) IDE Controller (rev 02)
00:1f.2 SATA controller: Intel Corporation 82801GBM/GHM (ICH7 Family) SATA AHCI Controller (rev 02)
00:1f.3 SMBus: Intel Corporation N10/ICH 7 Family SMBus Controller (rev 02)
02:00.0 Ethernet controller: Marvell Technology Group Ltd. 88E8055 PCI-E Gigabit Ethernet Controller (rev 12)
05:00.0 Network controller: Intel Corporation PRO/Wireless 3945ABG [Golan] Network Connection (rev 02)
08:03.0 CardBus bridge: O2 Micro, Inc. OZ711MP1/MS1 MemoryCardBus Controller (rev 21)
08:03.1 CardBus bridge: O2 Micro, Inc. OZ711MP1/MS1 MemoryCardBus Controller (rev 21)
08:03.2 SD Host controller: O2 Micro, Inc. Integrated MMC/SD Controller (rev 01)
08:03.3 Bridge: O2 Micro, Inc. Integrated MS/xD Controller (rev 01)
08:03.4 FireWire (IEEE 1394): O2 Micro, Inc. Firewire (IEEE 1394) (rev 02)
09:00.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL-8139/8139C/8139C+ (rev 10)


Reading https://bugzilla.redhat.com/show_bug.cgi?id=487687
seemed to indicate a potential remediation with a module option
Attempted that ... no real effect.

$ sudo /sbin/rmmod iwl3945 && sudo /sbin/modprobe iwl3945 disable_hw_scan=1 && echo ok
ok


The hardware is operable to the point that iwlist can scan.


$ sudo /sbin/iwlist scanning | sed -e 's/2832 Emerson St //'
em1       Interface doesn't support scanning.

lo        Interface doesn't support scanning.

p2p1      Interface doesn't support scanning.

wlan0     Scan completed :
          Cell 01 - Address: F2:1F:56:94:59:45
                    Channel:1
                    Frequency:2.412 GHz (Channel 1)
                    Quality=28/70  Signal level=-82 dBm  
                    Encryption key:on
                    ESSID:"compass"
                    Bit Rates:1 Mb/s; 2 Mb/s; 5.5 Mb/s; 11 Mb/s; 6 Mb/s
                              9 Mb/s; 12 Mb/s; 18 Mb/s
                    Bit Rates:24 Mb/s; 36 Mb/s; 48 Mb/s; 54 Mb/s
                    Mode:Ad-Hoc
                    Extra:tsf=00000026e7334272
                    Extra: Last beacon: 2151ms ago
                    IE: Unknown: 0007636F6D70617373
                    IE: Unknown: 010882840B160C121824
                    IE: Unknown: 030101
                    IE: Unknown: 06020000
                    IE: Unknown: 32043048606C
          Cell 02 - Address: 00:04:5A:0E:F4:A9
                    Channel:1
                    Frequency:2.412 GHz (Channel 1)
                    Quality=56/70  Signal level=-54 dBm  
                    Encryption key:off
                    ESSID:"insouciant"
                    Bit Rates:1 Mb/s; 2 Mb/s; 5.5 Mb/s; 11 Mb/s
                    Mode:Master
                    Extra:tsf=00000014e298d14f
                    Extra: Last beacon: 2139ms ago
                    IE: Unknown: 001A3238333220456D6572736F6E20537420696E736F756369616E74
                    IE: Unknown: 010482848B96
                    IE: Unknown: 030101
          Cell 03 - Address: 00:1D:7E:64:D3:5B
                    Channel:6
                    Frequency:2.437 GHz (Channel 6)
                    Quality=38/70  Signal level=-72 dBm  
                    Encryption key:off
                    ESSID:"rubicund"
                    Bit Rates:1 Mb/s; 2 Mb/s; 5.5 Mb/s; 11 Mb/s; 18 Mb/s
                              24 Mb/s; 36 Mb/s; 54 Mb/s
                    Bit Rates:6 Mb/s; 9 Mb/s; 12 Mb/s; 48 Mb/s
                    Mode:Master
                    Extra:tsf=000001b9968ec51d
                    Extra: Last beacon: 1791ms ago
                    IE: Unknown: 00183238333220456D6572736F6E205374207275626963756E64
                    IE: Unknown: 010882848B962430486C
                    IE: Unknown: 030106
                    IE: Unknown: 2A0102
                    IE: Unknown: 2F0102
                    IE: Unknown: 32040C121860
                    IE: Unknown: DD090010180200F4010000
                    IE: Unknown: 2D1A1E181AFFFF000000000000000000000000000000000000000000
                    IE: Unknown: DD1E00904C331E181AFFFF000000000000000000000000000000000000000000
                    IE: Unknown: 3D16060D0000000000000000000000000000000000000000
                    IE: Unknown: DD1A00904C34060D0000000000000000000000000000000000000000
          Cell 04 - Address: 00:25:9C:63:75:8B
                    Channel:9
                    Frequency:2.452 GHz (Channel 9)
                    Quality=70/70  Signal level=-37 dBm  
                    Encryption key:off
                    ESSID:"acedia"
                    Bit Rates:1 Mb/s; 2 Mb/s; 5.5 Mb/s; 11 Mb/s; 18 Mb/s
                              24 Mb/s; 36 Mb/s; 54 Mb/s
                    Bit Rates:6 Mb/s; 9 Mb/s; 12 Mb/s; 48 Mb/s
                    Mode:Master
                    Extra:tsf=0000002f941725cb
                    Extra: Last beacon: 1708ms ago
                    IE: Unknown: 00163238333220456D6572736F6E20537420616365646961
                    IE: Unknown: 010882848B9624B0486C
                    IE: Unknown: 030109
                    IE: Unknown: 2A0100
                    IE: Unknown: 2F0100
                    IE: Unknown: 32048C129860
                    IE: Unknown: DD06001018020004
          Cell 05 - Address: 00:09:5B:9C:F3:D6
                    Channel:11
                    Frequency:2.462 GHz (Channel 11)
                    Quality=27/70  Signal level=-83 dBm  
                    Encryption key:on
                    ESSID:"NETGEAR"
                    Bit Rates:1 Mb/s; 2 Mb/s; 5.5 Mb/s; 11 Mb/s
                    Mode:Master
                    Extra:tsf=0000007d35e1c185
                    Extra: Last beacon: 1737ms ago
                    IE: Unknown: 00074E455447454152
                    IE: Unknown: 010482848B96
                    IE: Unknown: 03010B
                    IE: Unknown: 0406000200000000
                    IE: Unknown: 0505000100003F





$ cat o.tail_messages.out
Feb 19 15:10:27 hippie NetworkManager[939]: NetworkManager[939]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
Feb 19 15:10:27 hippie NetworkManager[939]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
Feb 19 15:10:27 hippie NetworkManager[939]: NetworkManager[939]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
Feb 19 15:10:32 hippie NetworkManager[939]: <info> (wlan0): supplicant interface state: scanning -> inactive
Feb 19 15:10:32 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): supplicant interface state: scanning -> inactive
Feb 19 15:16:24 hippie avahi-daemon[949]: Withdrawing workstation service for wlan0.
Feb 19 15:16:24 hippie NetworkManager[939]: <info> radio killswitch /sys/devices/pci0000:00/0000:00:1c.2/0000:05:00.0/ieee80211/phy0/rfkill0 disappeared
Feb 19 15:16:24 hippie NetworkManager[939]: NetworkManager[939]: <info> radio killswitch /sys/devices/pci0000:00/0000:00:1c.2/0000:05:00.0/ieee80211/phy0/rfkill0 disappeared
Feb 19 15:16:24 hippie kernel: [1126360.750634] iwl3945 0000:05:00.0: PCI INT A disabled
Feb 19 15:16:25 hippie NetworkManager[939]: <info> (wlan0): now unmanaged
Feb 19 15:16:25 hippie NetworkManager[939]: <info> (wlan0): device state change: disconnected -> unmanaged (reason 'removed') [30 10 36]
Feb 19 15:16:25 hippie NetworkManager[939]: <info> (wlan0): cleaning up...
Feb 19 15:16:25 hippie NetworkManager[939]: <warn> (3) failed to find interface name for index
Feb 19 15:16:25 hippie NetworkManager[939]: (nm-system.c:679):nm_system_iface_is_up: runtime check failed: (iface != NULL)
Feb 19 15:16:25 hippie NetworkManager[939]: <error> [1329693385.82760] [nm-system.c:681] nm_system_iface_is_up(): (unknown): failed to get interface link object
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): now unmanaged
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): device state change: disconnected -> unmanaged (reason 'removed') [30 10 36]
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): cleaning up...
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <warn> (3) failed to find interface name for index
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: (nm-system.c:679):nm_system_iface_is_up: runtime check failed: (iface != NULL)
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <error> [1329693385.82760] [nm-system.c:681] nm_system_iface_is_up(): (unknown): failed to get interface link object
Feb 19 15:16:25 hippie kernel: [1126361.314191] iwl3945: Intel(R) PRO/Wireless 3945ABG/BG Network Connection driver for Linux, in-tree:s
Feb 19 15:16:25 hippie kernel: [1126361.314201] iwl3945: Copyright(c) 2003-2011 Intel Corporation
Feb 19 15:16:25 hippie kernel: [1126361.314326] iwl3945 0000:05:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
Feb 19 15:16:25 hippie kernel: [1126361.355818] iwl3945 0000:05:00.0: Tunable channels: 11 802.11bg, 13 802.11a channels
Feb 19 15:16:25 hippie kernel: [1126361.355825] iwl3945 0000:05:00.0: Detected Intel Wireless WiFi Link 3945ABG
Feb 19 15:16:25 hippie kernel: [1126361.430633] iwl3945 0000:05:00.0: loaded firmware version 15.32.2.9
Feb 19 15:16:25 hippie kernel: [1126361.499740] ADDRCONF(NETDEV_UP): wlan0: link is not ready
Feb 19 15:16:25 hippie NetworkManager[939]: <info> (wlan0): driver supports SSID scans (scan_capa 0x01).
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): driver supports SSID scans (scan_capa 0x01).
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): new 802.11 WiFi device (driver: 'iwl3945' ifindex: 5)
Feb 19 15:16:25 hippie NetworkManager[939]: <info> (wlan0): new 802.11 WiFi device (driver: 'iwl3945' ifindex: 5)
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): exported as /org/freedesktop/NetworkManager/Devices/3
Feb 19 15:16:25 hippie NetworkManager[939]: <info> (wlan0): exported as /org/freedesktop/NetworkManager/Devices/3
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): now managed
Feb 19 15:16:25 hippie NetworkManager[939]: <info> (wlan0): now managed
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Feb 19 15:16:25 hippie NetworkManager[939]: <info> (wlan0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): preparing device.
Feb 19 15:16:25 hippie NetworkManager[939]: <info> (wlan0): preparing device.
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): deactivating device (reason 'managed') [2]
Feb 19 15:16:25 hippie NetworkManager[939]: <info> (wlan0): deactivating device (reason 'managed') [2]
Feb 19 15:16:25 hippie NetworkManager[939]: <info> found WiFi radio killswitch rfkill2 (at /sys/devices/pci0000:00/0000:00:1c.2/0000:05:00.0/ieee80211/phy1/rfkill2) (driver (unknown))
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <info> found WiFi radio killswitch rfkill2 (at /sys/devices/pci0000:00/0000:00:1c.2/0000:05:00.0/ieee80211/phy1/rfkill2) (driver (unknown))
Feb 19 15:16:25 hippie kernel: [1126361.728108] ADDRCONF(NETDEV_UP): wlan0: link is not ready
Feb 19 15:16:25 hippie NetworkManager[939]: <info> (wlan0): supplicant interface state: starting -> ready
Feb 19 15:16:25 hippie NetworkManager[939]: <info> (wlan0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): supplicant interface state: starting -> ready
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
Feb 19 15:16:25 hippie NetworkManager[939]: <info> (wlan0): supplicant interface state: ready -> inactive
Feb 19 15:16:25 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): supplicant interface state: ready -> inactive
Feb 19 15:16:56 hippie NetworkManager[939]: <info> Activation (wlan0) starting connection 'System 'acedia' (wlan0)'
Feb 19 15:16:56 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0) starting connection 'System 'acedia' (wlan0)'
Feb 19 15:16:56 hippie NetworkManager[939]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Feb 19 15:16:56 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Feb 19 15:16:56 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Feb 19 15:16:56 hippie NetworkManager[939]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Feb 19 15:16:56 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Feb 19 15:16:56 hippie NetworkManager[939]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Feb 19 15:16:56 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Feb 19 15:16:56 hippie NetworkManager[939]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Feb 19 15:16:56 hippie NetworkManager[939]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Feb 19 15:16:56 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Feb 19 15:16:56 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Feb 19 15:16:56 hippie NetworkManager[939]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Feb 19 15:16:56 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Feb 19 15:16:56 hippie NetworkManager[939]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Feb 19 15:16:56 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0/wireless): connection 'System 'acedia' (wlan0)' requires no security.  No secrets needed.
Feb 19 15:16:56 hippie NetworkManager[939]: <info> Activation (wlan0/wireless): connection 'System 'acedia' (wlan0)' requires no security.  No secrets needed.
Feb 19 15:16:56 hippie NetworkManager[939]: NetworkManager[939]: <info> Config: added 'ssid' value ''acedia''
Feb 19 15:16:56 hippie NetworkManager[939]: <info> Config: added 'ssid' value ''acedia''
Feb 19 15:16:56 hippie NetworkManager[939]: NetworkManager[939]: <info> Config: added 'scan_ssid' value '1'
Feb 19 15:16:56 hippie NetworkManager[939]: <info> Config: added 'scan_ssid' value '1'
Feb 19 15:16:56 hippie NetworkManager[939]: NetworkManager[939]: <info> Config: added 'key_mgmt' value 'NONE'
Feb 19 15:16:56 hippie NetworkManager[939]: <info> Config: added 'key_mgmt' value 'NONE'
Feb 19 15:16:56 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Feb 19 15:16:56 hippie NetworkManager[939]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Feb 19 15:16:56 hippie NetworkManager[939]: <info> Config: set interface ap_scan to 1
Feb 19 15:16:56 hippie NetworkManager[939]: NetworkManager[939]: <info> Config: set interface ap_scan to 1
Feb 19 15:16:56 hippie NetworkManager[939]: <info> (wlan0): supplicant interface state: inactive -> scanning
Feb 19 15:16:56 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): supplicant interface state: inactive -> scanning
Feb 19 15:17:17 hippie dhclient[2061]: DHCPREQUEST on p2p1 to 192.168.0.28 port 67
Feb 19 15:17:17 hippie NetworkManager[939]: DHCPREQUEST on p2p1 to 192.168.0.28 port 67
Feb 19 15:17:17 hippie dhclient[2061]: DHCPACK from 192.168.0.28
Feb 19 15:17:17 hippie NetworkManager[939]: DHCPACK from 192.168.0.28
Feb 19 15:17:17 hippie dhclient[2061]: bound to 192.168.0.26 -- renewal in 896 seconds.
Feb 19 15:17:17 hippie NetworkManager[939]: bound to 192.168.0.26 -- renewal in 896 seconds.
Feb 19 15:17:21 hippie avahi-daemon[949]: Withdrawing workstation service for wlan0.
Feb 19 15:17:21 hippie NetworkManager[939]: <info> radio killswitch /sys/devices/pci0000:00/0000:00:1c.2/0000:05:00.0/ieee80211/phy1/rfkill2 disappeared
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> radio killswitch /sys/devices/pci0000:00/0000:00:1c.2/0000:05:00.0/ieee80211/phy1/rfkill2 disappeared
Feb 19 15:17:21 hippie NetworkManager[939]: <info> (wlan0): now unmanaged
Feb 19 15:17:21 hippie NetworkManager[939]: <info> (wlan0): device state change: config -> unmanaged (reason 'removed') [50 10 36]
Feb 19 15:17:21 hippie NetworkManager[939]: <info> (wlan0): deactivating device (reason 'removed') [36]
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): now unmanaged
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): device state change: config -> unmanaged (reason 'removed') [50 10 36]
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): deactivating device (reason 'removed') [36]
Feb 19 15:17:21 hippie kernel: [1126417.149537] iwl3945 0000:05:00.0: PCI INT A disabled
Feb 19 15:17:21 hippie NetworkManager[939]: <warn> (5) failed to find interface name for index
Feb 19 15:17:21 hippie NetworkManager[939]: nm_system_iface_flush_routes: assertion `iface != NULL' failed
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <warn> (5) failed to find interface name for index
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: nm_system_iface_flush_routes: assertion `iface != NULL' failed
Feb 19 15:17:21 hippie NetworkManager[939]: <warn> (5) failed to find interface name for index
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <warn> (5) failed to find interface name for index
Feb 19 15:17:21 hippie NetworkManager[939]: <info> Policy set 'System p2p1' (p2p1) as default for IPv4 routing and DNS.
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> Policy set 'System p2p1' (p2p1) as default for IPv4 routing and DNS.
Feb 19 15:17:21 hippie NetworkManager[939]: <info> Policy set 'System p2p1' (p2p1) as default for IPv4 routing and DNS.
Feb 19 15:17:21 hippie NetworkManager[939]: <info> (wlan0): cleaning up...
Feb 19 15:17:21 hippie NetworkManager[939]: <warn> (5) failed to find interface name for index
Feb 19 15:17:21 hippie NetworkManager[939]: (nm-system.c:679):nm_system_iface_is_up: runtime check failed: (iface != NULL)
Feb 19 15:17:21 hippie NetworkManager[939]: <error> [1329693441.38772] [nm-system.c:681] nm_system_iface_is_up(): (unknown): failed to get interface link object
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> Policy set 'System p2p1' (p2p1) as default for IPv4 routing and DNS.
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): cleaning up...
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <warn> (5) failed to find interface name for index
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: (nm-system.c:679):nm_system_iface_is_up: runtime check failed: (iface != NULL)
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <error> [1329693441.38772] [nm-system.c:681] nm_system_iface_is_up(): (unknown): failed to get interface link object
Feb 19 15:17:21 hippie kernel: [1126417.182166] iwl3945: Intel(R) PRO/Wireless 3945ABG/BG Network Connection driver for Linux, in-tree:s
Feb 19 15:17:21 hippie kernel: [1126417.182173] iwl3945: Copyright(c) 2003-2011 Intel Corporation
Feb 19 15:17:21 hippie kernel: [1126417.182279] iwl3945 0000:05:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
Feb 19 15:17:21 hippie kernel: [1126417.223423] iwl3945 0000:05:00.0: Tunable channels: 11 802.11bg, 13 802.11a channels
Feb 19 15:17:21 hippie kernel: [1126417.223431] iwl3945 0000:05:00.0: Detected Intel Wireless WiFi Link 3945ABG
Feb 19 15:17:21 hippie NetworkManager[939]: <info> found WiFi radio killswitch rfkill3 (at /sys/devices/pci0000:00/0000:00:1c.2/0000:05:00.0/ieee80211/phy2/rfkill3) (driver (unknown))
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> found WiFi radio killswitch rfkill3 (at /sys/devices/pci0000:00/0000:00:1c.2/0000:05:00.0/ieee80211/phy2/rfkill3) (driver (unknown))
Feb 19 15:17:21 hippie NetworkManager[939]: <info> (wlan0): driver supports SSID scans (scan_capa 0x01).
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): driver supports SSID scans (scan_capa 0x01).
Feb 19 15:17:21 hippie NetworkManager[939]: <info> (wlan0): new 802.11 WiFi device (driver: 'iwl3945' ifindex: 6)
Feb 19 15:17:21 hippie NetworkManager[939]: <info> (wlan0): exported as /org/freedesktop/NetworkManager/Devices/4
Feb 19 15:17:21 hippie NetworkManager[939]: <info> (wlan0): now managed
Feb 19 15:17:21 hippie NetworkManager[939]: <info> (wlan0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Feb 19 15:17:21 hippie NetworkManager[939]: <info> (wlan0): bringing up device.
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): new 802.11 WiFi device (driver: 'iwl3945' ifindex: 6)
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): exported as /org/freedesktop/NetworkManager/Devices/4
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): now managed
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): bringing up device.
Feb 19 15:17:21 hippie kernel: [1126417.269228] iwl3945 0000:05:00.0: loaded firmware version 15.32.2.9
Feb 19 15:17:21 hippie kernel: [1126417.336903] ADDRCONF(NETDEV_UP): wlan0: link is not ready
Feb 19 15:17:21 hippie NetworkManager[939]: <info> (wlan0): preparing device.
Feb 19 15:17:21 hippie NetworkManager[939]: <info> (wlan0): deactivating device (reason 'managed') [2]
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): preparing device.
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): deactivating device (reason 'managed') [2]
Feb 19 15:17:21 hippie NetworkManager[939]: <info> (wlan0): supplicant interface state: starting -> ready
Feb 19 15:17:21 hippie NetworkManager[939]: <info> (wlan0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): supplicant interface state: starting -> ready
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
Feb 19 15:17:21 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): supplicant interface state: ready -> inactive
Feb 19 15:17:21 hippie NetworkManager[939]: <info> (wlan0): supplicant interface state: ready -> inactive
Feb 19 15:19:26 hippie NetworkManager[939]: <info> Activation (wlan0) starting connection 'System 'acedia' (wlan0)'
Feb 19 15:19:26 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0) starting connection 'System 'acedia' (wlan0)'
Feb 19 15:19:26 hippie NetworkManager[939]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Feb 19 15:19:26 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Feb 19 15:19:26 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Feb 19 15:19:26 hippie NetworkManager[939]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Feb 19 15:19:26 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Feb 19 15:19:26 hippie NetworkManager[939]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Feb 19 15:19:26 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Feb 19 15:19:26 hippie NetworkManager[939]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Feb 19 15:19:26 hippie NetworkManager[939]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Feb 19 15:19:26 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Feb 19 15:19:26 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Feb 19 15:19:26 hippie NetworkManager[939]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Feb 19 15:19:26 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Feb 19 15:19:26 hippie NetworkManager[939]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Feb 19 15:19:26 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0/wireless): connection 'System 'acedia' (wlan0)' requires no security.  No secrets needed.
Feb 19 15:19:26 hippie NetworkManager[939]: <info> Activation (wlan0/wireless): connection 'System 'acedia' (wlan0)' requires no security.  No secrets needed.
Feb 19 15:19:26 hippie NetworkManager[939]: <info> Config: added 'ssid' value ''acedia''
Feb 19 15:19:26 hippie NetworkManager[939]: NetworkManager[939]: <info> Config: added 'ssid' value ''acedia''
Feb 19 15:19:26 hippie NetworkManager[939]: <info> Config: added 'scan_ssid' value '1'
Feb 19 15:19:26 hippie NetworkManager[939]: <info> Config: added 'key_mgmt' value 'NONE'
Feb 19 15:19:26 hippie NetworkManager[939]: NetworkManager[939]: <info> Config: added 'scan_ssid' value '1'
Feb 19 15:19:26 hippie NetworkManager[939]: NetworkManager[939]: <info> Config: added 'key_mgmt' value 'NONE'
Feb 19 15:19:26 hippie NetworkManager[939]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Feb 19 15:19:26 hippie NetworkManager[939]: NetworkManager[939]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Feb 19 15:19:26 hippie NetworkManager[939]: <info> Config: set interface ap_scan to 1
Feb 19 15:19:26 hippie NetworkManager[939]: NetworkManager[939]: <info> Config: set interface ap_scan to 1
Feb 19 15:19:26 hippie NetworkManager[939]: <info> (wlan0): supplicant interface state: inactive -> scanning
Feb 19 15:19:26 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): supplicant interface state: inactive -> scanning
Feb 19 15:19:51 hippie NetworkManager[939]: NetworkManager[939]: <warn> Activation (wlan0/wireless): association took too long, failing activation.
Feb 19 15:19:51 hippie NetworkManager[939]: <warn> Activation (wlan0/wireless): association took too long, failing activation.
Feb 19 15:19:51 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): device state change: config -> failed (reason 'supplicant-timeout') [50 120 11]
Feb 19 15:19:51 hippie NetworkManager[939]: <info> (wlan0): device state change: config -> failed (reason 'supplicant-timeout') [50 120 11]
Feb 19 15:19:51 hippie NetworkManager[939]: NetworkManager[939]: <warn> Activation (wlan0) failed for access point ('acedia')
Feb 19 15:19:51 hippie NetworkManager[939]: <warn> Activation (wlan0) failed for access point ('acedia')
Feb 19 15:19:51 hippie NetworkManager[939]: NetworkManager[939]: <info> Marking connection 'System 'acedia' (wlan0)' invalid.
Feb 19 15:19:51 hippie NetworkManager[939]: <info> Marking connection 'System 'acedia' (wlan0)' invalid.
Feb 19 15:19:51 hippie NetworkManager[939]: NetworkManager[939]: <warn> Activation (wlan0) failed.
Feb 19 15:19:51 hippie NetworkManager[939]: <warn> Activation (wlan0) failed.
Feb 19 15:19:51 hippie NetworkManager[939]: NetworkManager[939]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
Feb 19 15:19:51 hippie NetworkManager[939]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
Feb 19 15:19:51 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): device state change: failed -> disconnected (reason 'none') [120 30 0]
Feb 19 15:19:51 hippie NetworkManager[939]: <info> (wlan0): device state change: failed -> disconnected (reason 'none') [120 30 0]
Feb 19 15:19:51 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): deactivating device (reason 'none') [0]
Feb 19 15:19:51 hippie NetworkManager[939]: <info> (wlan0): deactivating device (reason 'none') [0]
Feb 19 15:19:51 hippie NetworkManager[939]: <info> Policy set 'System p2p1' (p2p1) as default for IPv4 routing and DNS.
Feb 19 15:19:51 hippie NetworkManager[939]: NetworkManager[939]: <info> Policy set 'System p2p1' (p2p1) as default for IPv4 routing and DNS.
Feb 19 15:19:51 hippie NetworkManager[939]: <info> Policy set 'System p2p1' (p2p1) as default for IPv4 routing and DNS.
Feb 19 15:19:51 hippie NetworkManager[939]: NetworkManager[939]: <info> Policy set 'System p2p1' (p2p1) as default for IPv4 routing and DNS.
Feb 19 15:19:51 hippie NetworkManager[939]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
Feb 19 15:19:51 hippie NetworkManager[939]: NetworkManager[939]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
Feb 19 15:19:56 hippie NetworkManager[939]: <info> (wlan0): supplicant interface state: scanning -> inactive
Feb 19 15:19:56 hippie NetworkManager[939]: NetworkManager[939]: <info> (wlan0): supplicant interface state: scanning -> inactive

Comment 1 Kamil J. Dudek 2012-04-04 22:22:22 UTC
I was going to report a problem with WPA-Corporate, but recently WLAN stopped working on any networks. No security/WEP/WPA.

Intel Corporation PRO/Wireless 3945ABG [Golan] Network Connection (rev 02)
NetworkManager x86_64 0.9.4-2.git20120328_2.fc18


Apr  5 00:09:38 mewtwo NetworkManager[529]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Apr  5 00:09:38 mewtwo NetworkManager[529]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Apr  5 00:09:38 mewtwo NetworkManager[529]: <info> (wlan0): device state change: need-auth -> prepare (reason 'none') [60 40 0]
Apr  5 00:09:38 mewtwo NetworkManager[529]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Apr  5 00:09:38 mewtwo NetworkManager[529]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Apr  5 00:09:38 mewtwo NetworkManager[529]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Apr  5 00:09:38 mewtwo NetworkManager[529]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Apr  5 00:09:38 mewtwo NetworkManager[529]: <info> Activation (wlan0/wireless): connection 'weeeee 1' has security, and secrets exist.  No new secrets needed.
Apr  5 00:09:38 mewtwo NetworkManager[529]: <info> Config: added 'ssid' value 'weeeee'
Apr  5 00:09:38 mewtwo NetworkManager[529]: <info> Config: added 'scan_ssid' value '1'
Apr  5 00:09:38 mewtwo NetworkManager[529]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
Apr  5 00:09:38 mewtwo NetworkManager[529]: <info> Config: added 'psk' value '<omitted>'
Apr  5 00:09:38 mewtwo NetworkManager[529]: <info> Config: added 'proto' value 'WPA RSN'
Apr  5 00:09:38 mewtwo NetworkManager[529]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Apr  5 00:09:39 mewtwo NetworkManager[529]: <info> Config: set interface ap_scan to 1
Apr  5 00:09:39 mewtwo NetworkManager[529]: <info> (wlan0): supplicant interface state: disconnected -> scanning
Apr  5 00:09:42 mewtwo NetworkManager[529]: <info> (wlan0): supplicant interface state: scanning -> authenticating
Apr  5 00:09:42 mewtwo NetworkManager[529]: <info> (wlan0): supplicant interface state: authenticating -> associating
Apr  5 00:09:42 mewtwo NetworkManager[529]: <info> (wlan0): supplicant interface state: associating -> associated
Apr  5 00:09:52 mewtwo NetworkManager[529]: <info> (wlan0): supplicant interface state: associated -> disconnected
Apr  5 00:09:53 mewtwo NetworkManager[529]: <info> (wlan0): supplicant interface state: disconnected -> scanning
Apr  5 00:09:56 mewtwo NetworkManager[529]: <info> (wlan0): supplicant interface state: scanning -> authenticating
Apr  5 00:09:56 mewtwo NetworkManager[529]: <info> (wlan0): supplicant interface state: authenticating -> associating
Apr  5 00:09:56 mewtwo NetworkManager[529]: <info> (wlan0): supplicant interface state: associating -> associated
Apr  5 00:10:04 mewtwo NetworkManager[529]: <warn> Activation (wlan0/wireless): association took too long.
Apr  5 00:10:04 mewtwo NetworkManager[529]: <info> (wlan0): device state change: config -> need-auth (reason 'none') [50 60 0]
Apr  5 00:10:04 mewtwo NetworkManager[529]: <warn> Activation (wlan0/wireless): asking for new secrets
Apr  5 00:10:04 mewtwo NetworkManager[529]: <info> (wlan0): supplicant interface state: associated -> disconnected
Apr  5 00:10:04 mewtwo NetworkManager[529]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
Apr  5 00:10:09 mewtwo NetworkManager[529]: get_secret_flags: assertion `is_secret_prop (setting, secret_name, error)' failed

Randomly, I can see my favorite line:
device state change: failed -> disconnected (reason 'none') [120 30 0]

Comment 2 Fedora End Of Life 2013-01-16 15:11:30 UTC
This message is a reminder that Fedora 16 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 16. 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 '16'.

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 16'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 16 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, you are encouraged to click on 
"Clone This Bug" and open it against that version of Fedora.

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 3 Fedora End Of Life 2013-02-13 16:33:00 UTC
Fedora 16 changed to end-of-life (EOL) status on 2013-02-12. Fedora 16 is 
no longer maintained, which means that it will not receive any further 
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of 
Fedora please feel free to reopen this bug against that version.

Thank you for reporting this bug and we are sorry it could not be fixed.