Hi all, I've been having this issue with NM for some time and would kill to get it solved. My laptop (a Dell E1505) has an Intel 3945 device and wants to connect to a Cisco Aironet 1130AG access point using WPA2-Personal with AES CCMP. The distro is a fully updated Debian Sid, running the 2.6.25 kernel. NM version is 0.6.6.
When I set up the connection "from scratch" (entering the key, specifying the security settings, etc.) everything works fine. I associate, DHCP fires up, all is good. However, once the connection is brought down (say, by disabling wireless through the NM applet) I cannot reassociate without going through the initial configuration all over again. There appears to be some kind of key problem going on. I'm including the output of /var/log/messages below for each case. The sticking point appears to be this step: NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 psk <key>' In the first case (starting from scratch), this returns OK. When attempting to reconnect, it returns FAIL. I am not enough of a wifi guru to know whether this problem is likely to stem from NM, from wpa-supplicant, from the drivers, from my AP, or from the moon. I tried a bit of searching here, but couldn't find the right term to narrow things down. Any pointers in the right direction would be tremendously appreciated. If there's any other information I can provide, I would be eager to do so. Thanks, Todd /var/log/messages - Initial Connection (works) Jun 17 20:05:23 hector dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/wlan0_rename for sub-path wlan0_rename.dbus.get.reason Jun 17 20:05:23 hector NetworkManager: <info> User Switch: /org/freedesktop/NetworkManager/Devices/wlan0_5f_rename / SOPHROSUNE Jun 17 20:05:23 hector NetworkManager: <info> Deactivating device wlan0_rename. Jun 17 20:05:23 hector NetworkManager: <info> Device wlan0_rename activation scheduled... Jun 17 20:05:23 hector NetworkManager: <info> Activation (wlan0_rename) started... Jun 17 20:05:23 hector NetworkManager: <info> Activation (wlan0_rename) Stage 1 of 5 (Device Prepare) scheduled... Jun 17 20:05:23 hector NetworkManager: <info> Activation (wlan0_rename) Stage 1 of 5 (Device Prepare) started... Jun 17 20:05:23 hector NetworkManager: <info> Activation (wlan0_rename) Stage 2 of 5 (Device Configure) scheduled... Jun 17 20:05:23 hector NetworkManager: <info> Activation (wlan0_rename) Stage 1 of 5 (Device Prepare) complete. Jun 17 20:05:23 hector NetworkManager: <info> Activation (wlan0_rename) Stage 2 of 5 (Device Configure) starting... Jun 17 20:05:23 hector NetworkManager: <info> Activation (wlan0_rename/wireless): access point 'SOPHROSUNE' is encrypted, and a key exists. No new key needed. Jun 17 20:05:24 hector NetworkManager: <info> SUP: sending command 'INTERFACE_ADD wlan0_rename^I^Iwext^I/var/run/wpa_supplicant^I' Jun 17 20:05:25 hector NetworkManager: <info> SUP: response was 'OK' Jun 17 20:05:25 hector NetworkManager: <info> SUP: sending command 'AP_SCAN 1' Jun 17 20:05:25 hector NetworkManager: <info> SUP: response was 'OK' Jun 17 20:05:25 hector NetworkManager: <info> SUP: sending command 'ADD_NETWORK' Jun 17 20:05:25 hector NetworkManager: <info> SUP: response was '0' Jun 17 20:05:25 hector NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 ssid 534f5048524f53554e45' Jun 17 20:05:25 hector NetworkManager: <info> SUP: response was 'OK' Jun 17 20:05:25 hector NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 proto WPA2' Jun 17 20:05:25 hector NetworkManager: <info> SUP: response was 'OK' Jun 17 20:05:25 hector NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 key_mgmt WPA-PSK' Jun 17 20:05:25 hector NetworkManager: <info> SUP: response was 'OK' Jun 17 20:05:25 hector NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 psk <key>' Jun 17 20:05:25 hector NetworkManager: <info> SUP: response was 'OK' Jun 17 20:05:25 hector NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 pairwise CCMP' Jun 17 20:05:25 hector NetworkManager: <info> SUP: response was 'OK' Jun 17 20:05:25 hector NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 group CCMP' Jun 17 20:05:25 hector NetworkManager: <info> SUP: response was 'OK' Jun 17 20:05:25 hector NetworkManager: <info> SUP: sending command 'ENABLE_NETWORK 0' Jun 17 20:05:25 hector NetworkManager: <info> SUP: response was 'OK' Jun 17 20:05:25 hector NetworkManager: <info> Activation (wlan0_rename) Stage 2 of 5 (Device Configure) complete. Jun 17 20:05:26 hector kernel: [ 592.016419] ADDRCONF(NETDEV_CHANGE): wlan0_rename: link becomes ready Jun 17 20:05:27 hector kernel: [ 592.516576] padlock: VIA PadLock not detected. Jun 17 20:05:27 hector modprobe: WARNING: Error inserting padlock_aes (/lib/modules/2.6.25-2-686/kernel/drivers/crypto/padlock-aes.ko): No such device Jun 17 20:05:27 hector NetworkManager: <info> Supplicant state changed: 1 Jun 17 20:05:27 hector NetworkManager: <info> Activation (wlan0_rename/wireless) Stage 2 of 5 (Device Configure) successful. Connected to access point 'SOPHROSUNE'. Jun 17 20:05:27 hector NetworkManager: <info> Activation (wlan0_rename) Stage 3 of 5 (IP Configure Start) scheduled. Jun 17 20:05:27 hector NetworkManager: <info> Activation (wlan0_rename) Stage 3 of 5 (IP Configure Start) started... Jun 17 20:05:28 hector NetworkManager: <info> Activation (wlan0_rename) Beginning DHCP transaction. Jun 17 20:05:28 hector NetworkManager: <info> Activation (wlan0_rename) Stage 3 of 5 (IP Configure Start) complete. Jun 17 20:05:28 hector NetworkManager: <info> DHCP daemon state is now 12 (successfully started) for interface wlan0_rename Jun 17 20:05:28 hector dhclient: eth1: unknown hardware address type 801 Jun 17 20:05:28 hector avahi-daemon[2437]: Joining mDNS multicast group on interface wlan0_rename.IPv6 with address fe80::218:deff:fe83:1850. Jun 17 20:05:28 hector avahi-daemon[2437]: New relevant interface wlan0_rename.IPv6 for mDNS. Jun 17 20:05:28 hector avahi-daemon[2437]: Registering new address record for fe80::218:deff:fe83:1850 on wlan0_rename.*. Jun 17 20:05:29 hector NetworkManager: <info> DHCP daemon state is now 1 (starting) for interface wlan0_rename Jun 17 20:05:29 hector dhclient: eth1: unknown hardware address type 801 Jun 17 20:05:31 hector dhclient: DHCPDISCOVER on wlan0_rename to 255.255.255.255 port 67 interval 6 Jun 17 20:05:31 hector NetworkManager: <info> Old device 'wlan0_rename' activating, won't change. Jun 17 20:05:32 hector dhclient: DHCPOFFER from 192.168.1.1 Jun 17 20:05:32 hector dhclient: DHCPREQUEST on wlan0_rename to 255.255.255.255 port 67 Jun 17 20:05:32 hector dhclient: DHCPACK from 192.168.1.1 Jun 17 20:05:32 hector avahi-daemon[2437]: Joining mDNS multicast group on interface wlan0_rename.IPv4 with address 192.168.0.62. Jun 17 20:05:32 hector avahi-daemon[2437]: New relevant interface wlan0_rename.IPv4 for mDNS. Jun 17 20:05:32 hector avahi-daemon[2437]: Registering new address record for 192.168.0.62 on wlan0_rename.IPv4. Jun 17 20:05:32 hector avahi-daemon[2437]: Withdrawing address record for 192.168.0.62 on wlan0_rename. Jun 17 20:05:32 hector avahi-daemon[2437]: Leaving mDNS multicast group on interface wlan0_rename.IPv4 with address 192.168.0.62. Jun 17 20:05:32 hector avahi-daemon[2437]: Interface wlan0_rename.IPv4 no longer relevant for mDNS. Jun 17 20:05:32 hector avahi-daemon[2437]: Joining mDNS multicast group on interface wlan0_rename.IPv4 with address 192.168.0.62. Jun 17 20:05:32 hector avahi-daemon[2437]: New relevant interface wlan0_rename.IPv4 for mDNS. Jun 17 20:05:32 hector avahi-daemon[2437]: Registering new address record for 192.168.0.62 on wlan0_rename.IPv4. Jun 17 20:05:32 hector NetworkManager: <info> DHCP daemon state is now 2 (bound) for interface wlan0_rename Jun 17 20:05:32 hector NetworkManager: <info> Activation (wlan0_rename) Stage 4 of 5 (IP Configure Get) scheduled... Jun 17 20:05:32 hector NetworkManager: <info> Activation (wlan0_rename) Stage 4 of 5 (IP Configure Get) started... Jun 17 20:05:32 hector dhclient: bound to 192.168.0.62 -- renewal in 35828 seconds. Jun 17 20:05:32 hector dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/wlan0_rename for sub-path wlan0_rename.dbus.get.host_name Jun 17 20:05:32 hector dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/wlan0_rename for sub-path wlan0_rename.dbus.get.domain_name Jun 17 20:05:32 hector dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/wlan0_rename for sub-path wlan0_rename.dbus.get.domain_search Jun 17 20:05:32 hector dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/wlan0_rename for sub-path wlan0_rename.dbus.get.nis_domain Jun 17 20:05:32 hector dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/wlan0_rename for sub-path wlan0_rename.dbus.get.nis_servers Jun 17 20:05:32 hector NetworkManager: <info> Retrieved the following IP4 configuration from the DHCP daemon: Jun 17 20:05:32 hector NetworkManager: <info> address 192.168.0.62 Jun 17 20:05:32 hector NetworkManager: <info> netmask 255.255.0.0 Jun 17 20:05:32 hector NetworkManager: <info> broadcast 192.168.255.255 Jun 17 20:05:32 hector NetworkManager: <info> gateway 192.168.1.1 Jun 17 20:05:32 hector NetworkManager: <info> nameserver 66.167.100.107 Jun 17 20:05:32 hector dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/wlan0_rename for sub-path wlan0_rename.dbus.get.interface_mtu Jun 17 20:05:32 hector NetworkManager: <info> Activation (wlan0_rename) Stage 5 of 5 (IP Configure Commit) scheduled... Jun 17 20:05:32 hector NetworkManager: <info> Activation (wlan0_rename) Stage 4 of 5 (IP Configure Get) complete. Jun 17 20:05:32 hector NetworkManager: <info> Activation (wlan0_rename) Stage 5 of 5 (IP Configure Commit) started... Jun 17 20:05:32 hector avahi-daemon[2437]: Withdrawing address record for 192.168.0.62 on wlan0_rename. Jun 17 20:05:32 hector avahi-daemon[2437]: Leaving mDNS multicast group on interface wlan0_rename.IPv4 with address 192.168.0.62. Jun 17 20:05:32 hector avahi-daemon[2437]: Interface wlan0_rename.IPv4 no longer relevant for mDNS. Jun 17 20:05:32 hector avahi-daemon[2437]: Withdrawing address record for fe80::218:deff:fe83:1850 on wlan0_rename. Jun 17 20:05:32 hector avahi-daemon[2437]: Leaving mDNS multicast group on interface wlan0_rename.IPv6 with address fe80::218:deff:fe83:1850. Jun 17 20:05:32 hector avahi-daemon[2437]: Interface wlan0_rename.IPv6 no longer relevant for mDNS. Jun 17 20:05:32 hector avahi-daemon[2437]: Joining mDNS multicast group on interface wlan0_rename.IPv4 with address 192.168.0.62. Jun 17 20:05:32 hector avahi-daemon[2437]: New relevant interface wlan0_rename.IPv4 for mDNS. Jun 17 20:05:32 hector avahi-daemon[2437]: Registering new address record for 192.168.0.62 on wlan0_rename.IPv4. Jun 17 20:05:33 hector NetworkManager: <info> DHCP returned name servers but system has disabled dynamic modification! Jun 17 20:05:33 hector NetworkManager: <info> Activation (wlan0_rename) successful, device activated. Jun 17 20:05:33 hector NetworkManager: <info> Activation (wlan0_rename) Finish handler scheduled. Jun 17 20:05:33 hector NetworkManager: <info> Activation (wlan0_rename) Stage 5 of 5 (IP Configure Commit) complete. Jun 17 20:05:34 hector avahi-daemon[2437]: Joining mDNS multicast group on interface wlan0_rename.IPv6 with address fe80::218:deff:fe83:1850. Jun 17 20:05:34 hector avahi-daemon[2437]: New relevant interface wlan0_rename.IPv6 for mDNS. Jun 17 20:05:34 hector avahi-daemon[2437]: Registering new address record for fe80::218:deff:fe83:1850 on wlan0_rename.*. /var/log/messages - Resetting Connection (fails) Jun 17 20:07:35 hector NetworkManager: <info> User Switch: /org/freedesktop/NetworkManager/Devices/wlan0_5f_rename / SOPHROSUNE Jun 17 20:07:35 hector NetworkManager: <info> Deactivating device wlan0_rename. Jun 17 20:07:35 hector NetworkManager: <info> Device wlan0_rename activation scheduled... Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename) started... Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename) Stage 1 of 5 (Device Prepare) scheduled... Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename) Stage 1 of 5 (Device Prepare) started... Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename) Stage 2 of 5 (Device Configure) scheduled... Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename) Stage 1 of 5 (Device Prepare) complete. Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename) Stage 2 of 5 (Device Configure) starting... Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename/wireless): access point 'SOPHROSUNE' is encrypted, but NO valid key exists. New key needed. Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename) New wireless user key requested for network 'SOPHROSUNE'. Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename) Stage 2 of 5 (Device Configure) complete. Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename) New wireless user key for network 'SOPHROSUNE' received. Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename) Stage 1 of 5 (Device Prepare) scheduled... Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename) Stage 1 of 5 (Device Prepare) started... Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename) Stage 2 of 5 (Device Configure) scheduled... Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename) Stage 1 of 5 (Device Prepare) complete. Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename) Stage 2 of 5 (Device Configure) starting... Jun 17 20:07:35 hector NetworkManager: <info> Activation (wlan0_rename/wireless): access point 'SOPHROSUNE' is encrypted, and a key exists. No new key needed. Jun 17 20:07:36 hector NetworkManager: <info> SUP: sending command 'INTERFACE_ADD wlan0_rename^I^Iwext^I/var/run/wpa_supplicant^I' Jun 17 20:07:36 hector NetworkManager: <info> SUP: response was 'OK' Jun 17 20:07:36 hector NetworkManager: <info> SUP: sending command 'AP_SCAN 1' Jun 17 20:07:36 hector NetworkManager: <info> SUP: response was 'OK' Jun 17 20:07:36 hector NetworkManager: <info> SUP: sending command 'ADD_NETWORK' Jun 17 20:07:36 hector NetworkManager: <info> SUP: response was '0' Jun 17 20:07:36 hector NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 ssid 534f5048524f53554e45' Jun 17 20:07:36 hector NetworkManager: <info> SUP: response was 'OK' Jun 17 20:07:36 hector NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 proto WPA2' Jun 17 20:07:36 hector NetworkManager: <info> SUP: response was 'OK' Jun 17 20:07:36 hector NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 key_mgmt WPA-PSK' Jun 17 20:07:36 hector NetworkManager: <info> SUP: response was 'OK' Jun 17 20:07:36 hector NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 psk <key>' Jun 17 20:07:36 hector NetworkManager: <info> SUP: response was 'FAIL' Jun 17 20:07:36 hector NetworkManager: <WARN> nm_utils_supplicant_request_with_check(): real_write_supplicant_config: supplicant error for 'SET_NETWORK 0 psk <key>'. Response: 'FAIL' Jun 17 20:07:36 hector NetworkManager: <WARN> real_act_stage2_config(): Activation (wlan0_rename/wireless): couldn't send wireless configuration to the supplicant. Jun 17 20:07:36 hector NetworkManager: <info> Activation (wlan0_rename) failure scheduled... Jun 17 20:07:36 hector NetworkManager: <info> Activation (wlan0_rename) Stage 2 of 5 (Device Configure) complete. Jun 17 20:07:36 hector NetworkManager: <info> Activation (wlan0_rename) failed for access point (SOPHROSUNE) Jun 17 20:07:36 hector NetworkManager: <info> Activation (wlan0_rename) failed. Jun 17 20:07:36 hector NetworkManager: <info> Deactivating device wlan0_rename. Jun 17 20:07:37 hector kernel: [ 719.839907] ACPI: PCI interrupt for device 0000:0b:00.0 disabled Jun 17 20:07:38 hector kernel: [ 728.462010] ACPI: PCI Interrupt 0000:0b:00.0[A] -> GSI 16 (level, low) -> IRQ 16 Jun 17 20:07:38 hector kernel: [ 728.512536] ADDRCONF(NETDEV_UP): wlan0_rename: link is not ready _______________________________________________ NetworkManager-list mailing list [email protected] http://mail.gnome.org/mailman/listinfo/networkmanager-list
