Public bug reported:

Binary package hint: network-manager-gnome

Hello! Weird issue with the network-manager applet. (Up-to-date Gutsy,
on a laptop with an Intel ipw3945 chipset, running the 2.6.22-8-generic
kernel.) This started quite some time ago (maybe more than a month), but
I initially dismissed it (I had bigger problems with it). It still
didn't go away, though.

When I login (at home) the NM attempts to connect automatically to my
wifi router, which it knows about and whose password is in the keyring.
The keyring asks for the password, I give it, and then the weirdness
starts: NM acts as it does during the connection phase, it actually
connects (I can see the ESSID associated in iwconfig), but then
disconnects and asks for the network key.

When I give it the network key it goes through the same stages again,
and asks again for the key.

While trying to see what's wrong I noticed that if I manually start
"sudo dhclient eth1" (eth1 is the wireless card) and _then_ I give NM
the key (either at start when I unlock the keyring, or afterwards when
it asks for it) the connection is completed correctly. Everything works
afterwards (well, there are some bugs with the RF-switch, but that's
another bug report.)

I'm quite sure NM also starts the dhclient, because sometimes the one I
start manually complains about files already existing before quitting.
Also, every once in a blue moon NM actually completes the connection
itself without me starting the dhclient.

I suspect some sort of timeout causes it to thing dhclient isn't working
and to kill it, but I'm just guessing.

I'm leaving the country in a couple of days, so I may not be able to
answer any questions until a couple of weeks from now, but maybe someone
can take a look at likely causes and see something fishy.

Here's what dmesg says when the card is detected:
[   17.416000] ipw3945: Intel(R) PRO/Wireless 3945 Network Connection driver 
for Linux, 1.2.1mp
[   17.416000] ipw3945: Copyright(c) 2003-2006 Intel Corporation
[   17.420000] ACPI: PCI Interrupt 0000:0c:00.0[A] -> GSI 17 (level, low) -> 
IRQ 17
[   17.420000] PCI: Setting latency timer of device 0000:0c:00.0 to 64
[   17.420000] ipw3945: Detected Intel PRO/Wireless 3945ABG Network Connection

Here's what I have in my /var/log/daemon.log from my last boot around
the time NM started. (I'm sorry, I don't remember for sure, but I think
I might have started dhclient from the start; if I have time before I
leave tomorrow I'll make a new post with a failure recorded, too.) It's
mixed with messages from Avahi, I left them as they might be relevant.

Jul 23 01:25:18 cimer NetworkManager: <info>  starting... 
Jul 23 01:25:18 cimer NetworkManager: <info>  nm_policy_device_change_check:: 
!old_dev && !new_dev!! 
Jul 23 01:25:22 cimer pdnsd[8056]: pdnsd-1.2.6-par starting. 
Jul 23 01:25:22 cimer pdnsd[8056]: icmp ping: sendto() failed: Network is 
unreachable.
Jul 23 01:25:22 cimer pdnsd[8056]: icmp ping: sendto() failed: Network is 
unreachable.
Jul 23 01:25:22 cimer rpc.statd[8189]: Version 1.1.0 Starting
Jul 23 01:25:22 cimer rpc.statd[8189]: statd running as root. chown 
/var/lib/nfs/sm to choose different user 
Jul 23 01:25:23 cimer ntpd[8324]: ntpd [EMAIL PROTECTED] Fri May 18 15:01:09 
UTC 2007 (1)
Jul 23 01:25:23 cimer ntpd[8336]: precision = 1.000 usec
Jul 23 01:25:23 cimer ntpd[8336]: Listening on interface #0 wildcard, 
0.0.0.0#123 Disabled
Jul 23 01:25:23 cimer ntpd[8336]: Listening on interface #1 wildcard, ::#123 
Disabled
Jul 23 01:25:23 cimer ntpd[8336]: Listening on interface #2 lo, ::1#123 Enabled
Jul 23 01:25:23 cimer ntpd[8336]: Listening on interface #3 lo, 127.0.0.1#123 
Enabled
Jul 23 01:25:23 cimer ntpd[8336]: kernel time sync status 0040
Jul 23 01:25:23 cimer ntpd[8336]: frequency initialized -19.599 PPM from 
/var/lib/ntp/ntp.drift
Jul 23 01:25:23 cimer ntpd[8336]: Cannot find existing interface for address 
82.211.81.145
Jul 23 01:25:23 cimer ntpd[8336]: configuration of 82.211.81.145 failed
Jul 23 01:25:25 cimer NetworkManager: <info>  eth1: Device is fully-supported 
using driver 'ipw3945'. 
Jul 23 01:25:25 cimer NetworkManager: <info>  nm_device_init(): waiting for 
device's worker thread to start 
Jul 23 01:25:25 cimer NetworkManager: <info>  nm_device_init(): device's worker 
thread started, continuing. 
Jul 23 01:25:25 cimer NetworkManager: <info>  Now managing wireless (802.11) 
device 'eth1'. 
Jul 23 01:25:25 cimer NetworkManager: <info>  Deactivating device eth1. 
Jul 23 01:25:25 cimer NetworkManager: <info>  eth0: Device is fully-supported 
using driver 'tg3'. 
Jul 23 01:25:25 cimer NetworkManager: <info>  nm_device_init(): waiting for 
device's worker thread to start 
Jul 23 01:25:25 cimer NetworkManager: <info>  nm_device_init(): device's worker 
thread started, continuing. 
Jul 23 01:25:25 cimer NetworkManager: <info>  Now managing wired Ethernet 
(802.3) device 'eth0'. 
Jul 23 01:25:25 cimer NetworkManager: <info>  Deactivating device eth0. 
Jul 23 01:25:25 cimer NetworkManager: <debug> [1185146725.996723] 
nm_hal_device_added(): New device added (hal udi is 
'/org/freedesktop/Hal/devices/storage_model_DVD__RW_AD_5540A'). 
Jul 23 01:25:25 cimer NetworkManager: <info>  nm_device_set_active_link start 
Jul 23 01:25:25 cimer NetworkManager: <info>  Will activate wired connection 
'eth0' because it now has a link. 
Jul 23 01:25:25 cimer NetworkManager: <info>  nm_device_set_active_link start 
Jul 23 01:25:25 cimer NetworkManager: <info>  nm_policy_device_change_check:: 
!old_dev && !new_dev!! 
Jul 23 01:25:26 cimer avahi-daemon[8647]: Found user 'avahi' (UID 107) and 
group 'avahi' (GID 113).
Jul 23 01:25:26 cimer avahi-daemon[8647]: Successfully dropped root privileges.
Jul 23 01:25:26 cimer avahi-daemon[8647]: avahi-daemon 0.6.19 starting up.
Jul 23 01:25:26 cimer avahi-daemon[8647]: Successfully called chroot().
Jul 23 01:25:26 cimer avahi-daemon[8647]: Successfully dropped remaining 
capabilities.
Jul 23 01:25:26 cimer avahi-daemon[8647]: No service file found in 
/etc/avahi/services.
Jul 23 01:25:26 cimer avahi-daemon[8647]: Network interface enumeration 
completed.
Jul 23 01:25:26 cimer avahi-daemon[8647]: Registering HINFO record with values 
'I686'/'LINUX'.
Jul 23 01:25:26 cimer avahi-daemon[8647]: Server startup complete. Host name is 
cimer.local. Local service cookie is 645521888.
Jul 23 01:25:34 cimer NetworkManager: <info>  Updating allowed wireless network 
lists. 
Jul 23 01:25:34 cimer NetworkManager: <info>  nm_policy_device_change_check:: 
!old_dev && !new_dev!! 
Jul 23 01:25:35 cimer last message repeated 7 times
Jul 23 01:25:35 cimer NetworkManager: <info>  SWITCH: no current connection, 
found better connection 'eth1'. 
Jul 23 01:25:35 cimer NetworkManager: <info>  nm_policy_device_change_check:: 
lets try to switch device! 
Jul 23 01:25:35 cimer NetworkManager: <info>  Will activate connection 
'eth1/SpeedTouch324B2B'. 
Jul 23 01:25:35 cimer NetworkManager: <info>  Device eth1 activation 
scheduled... 
Jul 23 01:25:35 cimer NetworkManager: <info>  Activation (eth1) started... 
Jul 23 01:25:35 cimer NetworkManager: <info>  Activation (eth1) Stage 1 of 5 
(Device Prepare) scheduled... 
Jul 23 01:25:35 cimer NetworkManager: <info>  Activation (eth1) Stage 1 of 5 
(Device Prepare) started... 
Jul 23 01:25:35 cimer NetworkManager: <info>  Activation (eth1) Stage 2 of 5 
(Device Configure) scheduled... 
Jul 23 01:25:35 cimer NetworkManager: <info>  Activation (eth1) Stage 1 of 5 
(Device Prepare) complete. 
Jul 23 01:25:35 cimer NetworkManager: <info>  Activation (eth1) Stage 2 of 5 
(Device Configure) starting... 
Jul 23 01:25:35 cimer NetworkManager: <info>  Activation (eth1/wireless): 
access point 'SpeedTouch324B2B' is encrypted, but NO valid key exists.  New key 
needed. 
Jul 23 01:25:35 cimer NetworkManager: <info>  Activation (eth1) New wireless 
user key requested for network 'SpeedTouch324B2B'. 
Jul 23 01:25:35 cimer NetworkManager: <info>  Activation (eth1) Stage 2 of 5 
(Device Configure) complete. 
Jul 23 01:25:53 cimer NetworkManager: <info>  Activation (eth1) New wireless 
user key for network 'SpeedTouch324B2B' received. 
Jul 23 01:25:53 cimer NetworkManager: <info>  Activation (eth1) Stage 1 of 5 
(Device Prepare) scheduled... 
Jul 23 01:25:53 cimer NetworkManager: <info>  Activation (eth1) Stage 1 of 5 
(Device Prepare) started... 
Jul 23 01:25:53 cimer NetworkManager: <info>  Activation (eth1) Stage 2 of 5 
(Device Configure) scheduled... 
Jul 23 01:25:53 cimer NetworkManager: <info>  Activation (eth1) Stage 1 of 5 
(Device Prepare) complete. 
Jul 23 01:25:53 cimer NetworkManager: <info>  Activation (eth1) Stage 2 of 5 
(Device Configure) starting... 
Jul 23 01:25:53 cimer NetworkManager: <info>  Activation (eth1/wireless): 
access point 'SpeedTouch324B2B' is encrypted, and a key exists.  No new key 
needed. 
Jul 23 01:25:53 cimer NetworkManager: <info>  SUP: sending command 
'INTERFACE_ADD eth1^I^Iwext^I/var/run/wpa_supplicant^I' 
Jul 23 01:25:54 cimer NetworkManager: <info>  SUP: response was 'OK' 
Jul 23 01:25:54 cimer NetworkManager: <info>  SUP: sending command 'AP_SCAN 1' 
Jul 23 01:25:54 cimer NetworkManager: <info>  SUP: response was 'OK' 
Jul 23 01:25:54 cimer NetworkManager: <info>  SUP: sending command 
'ADD_NETWORK' 
Jul 23 01:25:54 cimer NetworkManager: <info>  SUP: response was '0' 
Jul 23 01:25:54 cimer NetworkManager: <info>  SUP: sending command 'SET_NETWORK 
0 ssid 5370656564546f756368333234423242' 
Jul 23 01:25:54 cimer NetworkManager: <info>  SUP: response was 'OK' 
Jul 23 01:25:54 cimer NetworkManager: <info>  SUP: sending command 'SET_NETWORK 
0 proto WPA2' 
Jul 23 01:25:54 cimer NetworkManager: <info>  SUP: response was 'OK' 
Jul 23 01:25:54 cimer NetworkManager: <info>  SUP: sending command 'SET_NETWORK 
0 key_mgmt WPA-PSK' 
Jul 23 01:25:54 cimer NetworkManager: <info>  SUP: response was 'OK' 
Jul 23 01:25:54 cimer NetworkManager: <info>  SUP: sending command 'SET_NETWORK 
0 psk <key>' 
Jul 23 01:25:54 cimer NetworkManager: <info>  SUP: response was 'OK' 
Jul 23 01:25:54 cimer NetworkManager: <info>  SUP: sending command 
'ENABLE_NETWORK 0' 
Jul 23 01:25:54 cimer NetworkManager: <info>  SUP: response was 'OK' 
Jul 23 01:25:54 cimer NetworkManager: <info>  Activation (eth1) Stage 2 of 5 
(Device Configure) complete. 
Jul 23 01:25:54 cimer dhclient: Internet Systems Consortium DHCP Client V3.0.5
Jul 23 01:25:54 cimer dhclient: Copyright 2004-2006 Internet Systems Consortium.
Jul 23 01:25:54 cimer dhclient: All rights reserved.
Jul 23 01:25:54 cimer dhclient: For info, please visit 
http://www.isc.org/sw/dhcp/
Jul 23 01:25:54 cimer dhclient: 
Jul 23 01:25:55 cimer dhclient: Listening on LPF/eth1/00:18:de:b2:c8:80
Jul 23 01:25:55 cimer dhclient: Sending on   LPF/eth1/00:18:de:b2:c8:80
Jul 23 01:25:55 cimer dhclient: Sending on   Socket/fallback
Jul 23 01:25:58 cimer dhclient: DHCPREQUEST on eth1 to 255.255.255.255 port 67
Jul 23 01:25:58 cimer NetworkManager: <info>  nm_device_set_active_link start 
Jul 23 01:25:58 cimer NetworkManager: <info>  Activation (eth1/wireless) Stage 
2 of 5 (Device Configure) successful.  Connected to access point 
'SpeedTouch324B2B'. 
Jul 23 01:25:58 cimer NetworkManager: <info>  Activation (eth1) Stage 3 of 5 
(IP Configure Start) scheduled. 
Jul 23 01:25:58 cimer NetworkManager: <info>  Activation (eth1) Stage 3 of 5 
(IP Configure Start) started... 
Jul 23 01:25:58 cimer avahi-daemon[8647]: Registering new address record for 
fe80::218:deff:feb2:c880 on eth1.*.
Jul 23 01:25:59 cimer NetworkManager: <info>  Activation (eth1) Beginning DHCP 
transaction. 
Jul 23 01:25:59 cimer NetworkManager: <info>  Activation (eth1) Stage 3 of 5 
(IP Configure Start) complete. 
Jul 23 01:25:59 cimer NetworkManager: <info>  DHCP daemon state is now 12 
(successfully started) for interface eth1 
Jul 23 01:26:00 cimer NetworkManager: <info>  DHCP daemon state is now 1 
(starting) for interface eth1 
Jul 23 01:26:03 cimer dhclient: DHCPREQUEST on eth1 to 255.255.255.255 port 67
Jul 23 01:26:03 cimer dhclient: DHCPACK from 192.168.1.254
Jul 23 01:26:03 cimer avahi-daemon[8647]: Joining mDNS multicast group on 
interface eth1.IPv4 with address 192.168.1.66.
Jul 23 01:26:03 cimer avahi-daemon[8647]: New relevant interface eth1.IPv4 for 
mDNS.
Jul 23 01:26:03 cimer avahi-daemon[8647]: Registering new address record for 
192.168.1.66 on eth1.IPv4.
Jul 23 01:26:03 cimer dhclient: bound to 192.168.1.66 -- renewal in 34446 
seconds.
Jul 23 01:26:03 cimer NetworkManager: <info>  DHCP daemon state is now 4 
(reboot) for interface eth1 
Jul 23 01:26:03 cimer NetworkManager: <info>  Activation (eth1) Stage 4 of 5 
(IP Configure Get) scheduled... 
Jul 23 01:26:03 cimer NetworkManager: <info>  Activation (eth1) Stage 4 of 5 
(IP Configure Get) started... 
Jul 23 01:26:03 cimer NetworkManager: <info>  Retrieved the following IP4 
configuration from the DHCP daemon: 
Jul 23 01:26:03 cimer NetworkManager: <info>    address 192.168.1.66 
Jul 23 01:26:03 cimer NetworkManager: <info>    netmask 255.255.255.0 
Jul 23 01:26:03 cimer NetworkManager: <info>    broadcast 192.168.1.255 
Jul 23 01:26:03 cimer NetworkManager: <info>    gateway 192.168.1.254 
Jul 23 01:26:03 cimer NetworkManager: <info>    nameserver 127.0.0.1 
Jul 23 01:26:03 cimer NetworkManager: <info>    nameserver 192.168.1.254 
Jul 23 01:26:03 cimer NetworkManager: <info>    domain name 'lan' 
Jul 23 01:26:03 cimer NetworkManager: <info>  Activation (eth1) Stage 5 of 5 
(IP Configure Commit) scheduled... 
Jul 23 01:26:03 cimer NetworkManager: <info>  Activation (eth1) Stage 4 of 5 
(IP Configure Get) complete. 
Jul 23 01:26:03 cimer NetworkManager: <info>  Activation (eth1) Stage 5 of 5 
(IP Configure Commit) started... 
Jul 23 01:26:03 cimer avahi-daemon[8647]: Withdrawing address record for 
192.168.1.66 on eth1.
Jul 23 01:26:03 cimer avahi-daemon[8647]: Leaving mDNS multicast group on 
interface eth1.IPv4 with address 192.168.1.66.
Jul 23 01:26:03 cimer avahi-daemon[8647]: Interface eth1.IPv4 no longer 
relevant for mDNS.
Jul 23 01:26:03 cimer avahi-daemon[8647]: Withdrawing address record for 
fe80::218:deff:feb2:c880 on eth1.
Jul 23 01:26:03 cimer avahi-daemon[8647]: Joining mDNS multicast group on 
interface eth1.IPv4 with address 192.168.1.66.
Jul 23 01:26:03 cimer avahi-daemon[8647]: New relevant interface eth1.IPv4 for 
mDNS.
Jul 23 01:26:03 cimer avahi-daemon[8647]: Registering new address record for 
192.168.1.66 on eth1.IPv4.
Jul 23 01:26:04 cimer NetworkManager: <info>  Clearing nscd hosts cache. 
Jul 23 01:26:04 cimer NetworkManager: <WARN>  nm_spawn_process(): 
nm_spawn_process('/usr/sbin/nscd -i hosts'): could not spawn process. (Failed 
to execute child process "/usr/sbin/nscd" (No such file or directory))  
Jul 23 01:26:04 cimer NetworkManager: <info>  Activation (eth1) successful, 
device activated. 
Jul 23 01:26:04 cimer NetworkManager: <info>  Activation (eth1) Finish handler 
scheduled. 
Jul 23 01:26:04 cimer NetworkManager: <info>  Activation (eth1) Stage 5 of 5 
(IP Configure Commit) complete. 
Jul 23 01:26:04 cimer ntpdate[11947]: the NTP socket is in use, exiting
Jul 23 01:26:05 cimer avahi-daemon[8647]: Registering new address record for 
fe80::218:deff:feb2:c880 on eth1.*.
Jul 23 01:26:06 cimer dhclient: DHCPREQUEST on eth1 to 255.255.255.255 port 67
Jul 23 01:26:06 cimer dhclient: DHCPACK from 192.168.1.254
Jul 23 01:26:06 cimer dhclient: bound to 192.168.1.66 -- renewal in 41157 
seconds.

** Affects: network-manager-applet (Ubuntu)
     Importance: Undecided
         Status: New

-- 
nm-applet doesn't work unless I start dhclient manually
https://bugs.launchpad.net/bugs/127649
You received this bug notification because you are a member of Ubuntu
Bugs, which is the bug contact for Ubuntu.

-- 
ubuntu-bugs mailing list
[email protected]
https://lists.ubuntu.com/mailman/listinfo/ubuntu-bugs

Reply via email to