2009/2/9 Dan Williams <[email protected]>: > On Sat, 2009-02-07 at 16:24 +0000, Stolz wrote: >> Whenever I switch from wired to wireless interface, it takes more than >> 45 seconds to get the wireless interface enabled. Looking at the logs, >> seems the problem is (k)Networkmanager sends a DHCPDISCOVER before >> been associated with any AP: > > Can you post some logs from when you enable the wireless interface? The > logs you've got start too late to be able to see exactly what's > happening. > > NM *should* be associating with the AP first (including all security > setup), and only when the wifi card says it's successfully associated > with the AP, will NetworkManager begin DHCP. > > Dan
Hello Dan. Here is the full log. I activated the WiFI interface exactly at 01:04:03 The log also can be read at http://rafb.net/p/K4H7x991.html Thanks for your help. Feb 10 01:03:33 dhcdbd: Started up. Feb 10 01:03:34 acpid: client connected from 30947[102:443] Feb 10 01:03:34 acpid: 1 client rule loaded Feb 10 01:03:35 NetworkManager: <info> starting... Feb 10 01:03:35 NetworkManager: <debug> [1234224215.249008] GentooReadConfig(): Found config_eth0 in /etc/conf.d/net. Feb 10 01:03:35 NetworkManager: <debug> [1234224215.249240] GentooReadConfig(): Found routes_eth0 in config. Feb 10 01:03:35 NetworkManager: <debug> [1234224215.249367] GentooReadConfig(): Found DNS nameservers in config. Feb 10 01:03:35 NetworkManager: <debug> [1234224215.249495] nm_system_device_get_system_config(): Using DNS nameservers "62.42.230.24 62.42.63.52" from config for device eth0. Feb 10 01:03:35 NetworkManager: <info> eth0: Device is fully-supported using driver '(null)'. Feb 10 01:03:35 NetworkManager: <info> nm_device_init(): waiting for device's worker thread to start Feb 10 01:03:35 NetworkManager: <info> nm_device_init(): device's worker thread started, continuing. Feb 10 01:03:35 NetworkManager: <info> Now managing wired Ethernet (802.3) device 'eth0'. Feb 10 01:03:35 NetworkManager: <info> Deactivating device eth0. Feb 10 01:03:35 NetworkManager: <info> Will activate wired connection 'eth0' because it now has a link. Feb 10 01:03:35 iwl3945 0000:0c:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17 Feb 10 01:03:35 iwl3945 0000:0c:00.0: restoring config space at offset 0x1 (was 0x100102, writing 0x100106) Feb 10 01:03:35 firmware: requesting iwlwifi-3945-1.ucode Feb 10 01:03:35 NetworkManager: <debug> [1234224215.325136] GentooReadConfig(): Enabling DHCP for device wlan0. Feb 10 01:03:35 NetworkManager: <info> wlan0: Driver '(null)' does not support carrier detection. Feb 10 01:03:35 You must switch to it manually. Feb 10 01:03:35 NetworkManager: <info> nm_device_init(): waiting for device's worker thread to start Feb 10 01:03:35 NetworkManager: <info> nm_device_init(): device's worker thread started, continuing. Feb 10 01:03:35 NetworkManager: <info> Now managing wired Ethernet (802.3) device 'wlan0'. Feb 10 01:03:35 NetworkManager: <info> Deactivating device wlan0. Feb 10 01:03:35 /etc/init.d/net.lo[30991]: WARNING: net.lo has already been started Feb 10 01:03:35 NetworkManager: <info> SWITCH: no current connection, found better connection 'eth0'. Feb 10 01:03:36 dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.reason Feb 10 01:03:36 NetworkManager: <info> Will activate connection 'eth0'. Feb 10 01:03:36 NetworkManager: <info> Device eth0 activation scheduled... Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) started... Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled... Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started... Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled... Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete. Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting... Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful. Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled. Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete. Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started... Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Get) scheduled... Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete. Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Get) started... Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled... Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Get) complete. Feb 10 01:03:36 NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) started... Feb 10 01:03:37 NetworkManager: <info> Setting hostname to 'vostro' Feb 10 01:03:37 NetworkManager: <info> Activation (eth0) successful, device activated. Feb 10 01:03:37 NetworkManager: <info> Activation (eth0) Finish handler scheduled. Feb 10 01:03:37 NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete. Feb 10 01:03:37 NetworkManager: <info> Activation (eth0) Finish handler scheduled. Feb 10 01:03:37 NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete. Feb 10 01:03:53 NetworkManager: <info> Updating allowed wireless network lists. Feb 10 01:03:53 NetworkManager: <WARN> nm_dbus_get_networks_cb(): error received: org.freedesktop.NetworkManagerInfo.NoNetworks - org.freedesktop.NetworkManagerInfo.NoNetworks. Feb 10 01:04:03 dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/wlan0 for sub-path wlan0.dbus.get.reason Feb 10 01:04:03 NetworkManager: <info> User Switch: /org/freedesktop/NetworkManager/Devices/wlan0 Feb 10 01:04:03 NetworkManager: <info> Deactivating device wlan0. Feb 10 01:04:03 NetworkManager: <info> Deactivating device wlan0. Feb 10 01:04:03 NetworkManager: <info> Device wlan0 activation scheduled... Feb 10 01:04:03 NetworkManager: <info> Deactivating device eth0. Feb 10 01:04:03 NetworkManager: <info> Activation (wlan0) started... Feb 10 01:04:03 NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... Feb 10 01:04:03 NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... Feb 10 01:04:03 NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... Feb 10 01:04:03 NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. Feb 10 01:04:03 NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... Feb 10 01:04:03 NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) successful. Feb 10 01:04:03 NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled. Feb 10 01:04:03 NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. Feb 10 01:04:03 NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started... Feb 10 01:04:04 NetworkManager: <info> Activation (wlan0) Beginning DHCP transaction. Feb 10 01:04:04 NetworkManager: <info> DHCP daemon state is now 12 (successfully started) for interface wlan0 Feb 10 01:04:04 NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete. Feb 10 01:04:04 dhclient: wmaster0: unknown hardware address type 801 Feb 10 01:04:04 dhclient: can't create /var/lib/dhclient/dhclient-wlan0.leases: No such file or directory Feb 10 01:04:05 NetworkManager: <info> DHCP daemon state is now 1 (starting) for interface wlan0 Feb 10 01:04:05 dhclient: wmaster0: unknown hardware address type 801 Feb 10 01:04:05 dhclient: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 8 Feb 10 01:04:13 dhclient: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 9 Feb 10 01:04:22 dhclient: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 10 Feb 10 01:04:32 dhclient: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 13 Feb 10 01:04:45 dhclient: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 13 Feb 10 01:04:49 NetworkManager: <info> Device 'wlan0' DHCP transaction took too long (>45s), stopping it. Feb 10 01:04:49 dhclient: wmaster0: unknown hardware address type 801 Feb 10 01:04:49 dhclient: can't create /var/lib/dhclient/dhclient-wlan0.leases: No such file or directory Feb 10 01:04:49 dhclient: wmaster0: unknown hardware address type 801 Feb 10 01:04:50 NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP Configure Timeout) started... Feb 10 01:04:50 NetworkManager: <info> No DHCP reply received. Automatically obtaining IP via Zeroconf. Feb 10 01:04:50 NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP Configure Timeout) scheduled... Feb 10 01:04:50 NetworkManager: <info> DHCP daemon state is now 14 (normal exit) for interface wlan0 Feb 10 01:04:50 NetworkManager: <info> DHCP daemon state is now 14 (normal exit) for interface wlan0 Feb 10 01:04:50 NetworkManager: <info> autoip: Sending probe #0 for IP address 169.254.3.193. Feb 10 01:04:50 NetworkManager: <info> autoip: Waiting for reply... Feb 10 01:04:52 NetworkManager: <info> autoip: Sending probe #1 for IP address 169.254.3.193. Feb 10 01:04:52 NetworkManager: <info> autoip: Waiting for reply... Feb 10 01:04:54 NetworkManager: <info> autoip: Sending probe #2 for IP address 169.254.3.193. Feb 10 01:04:54 NetworkManager: <info> autoip: Waiting for reply... Feb 10 01:04:57 NetworkManager: <info> autoip: Sending announce #0 for IP address 169.254.3.193. Feb 10 01:04:57 NetworkManager: <info> autoip: Waiting for reply... Feb 10 01:05:00 NetworkManager: <info> autoip: Sending announce #1 for IP address 169.254.3.193. Feb 10 01:05:00 NetworkManager: <info> autoip: Waiting for reply... Feb 10 01:05:03 NetworkManager: <info> autoip: Sending announce #2 for IP address 169.254.3.193. Feb 10 01:05:03 NetworkManager: <info> autoip: Waiting for reply... Feb 10 01:05:06 NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) scheduled... Feb 10 01:05:06 NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP Configure Timeout) complete. Feb 10 01:05:06 NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started... Feb 10 01:05:07 NetworkManager: <WARN> nm_system_set_hostname(): nm_system_set_hostname(): gethostbyaddr failed, h_errno = 2 Feb 10 01:05:07 NetworkManager: <info> Activation (wlan0) successful, device activated. Feb 10 01:05:07 NetworkManager: <info> Activation (wlan0) Finish handler scheduled. Feb 10 01:05:07 NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complete. _______________________________________________ NetworkManager-list mailing list [email protected] http://mail.gnome.org/mailman/listinfo/networkmanager-list
