DHCP lease not communicated to Network Manager

[Evgeny Kuznetsov]

Binary package hint: dhcdbd

After installing NetworkManager it detects ethernet cable and wireless networks. But when registering in the network, NetworkManager fails to receive IP from DHCP server.

Here is the part of /var/log/syslog:
Jun 29 04:14:28 localhost NetworkManager: <information>^IActivation (eth0) Beginning DHCP transaction.
Jun 29 04:14:28 localhost NetworkManager: <information>^IActivation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Jun 29 04:14:28 localhost NetworkManager: <information>^IDHCP daemon state is now 12 (successfully started) for interface eth0
Jun 29 04:14:29 localhost dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3
Jun 29 04:14:29 localhost dhclient: DHCPOFFER from 172.16.0.1
Jun 29 04:14:29 localhost dhclient: DHCPREQUEST on eth0 to 255.255.255.255 port 67
Jun 29 04:14:29 localhost dhclient: DHCPACK from 172.16.0.1
Jun 29 04:14:29 localhost dhclient: bound to 172.16.0.12 -- renewal in 265757 seconds.
Jun 29 04:14:37 localhost kernel: [17439882.524000] eth0: no IPv6 routers present
Jun 29 04:15:13 localhost NetworkManager: <information>^IDevice 'eth0' DHCP transaction took too long (>45s), stopping it.
Jun 29 04:15:13 localhost dhclient: DHCPRELEASE on eth0 to 172.16.0.1 port 67
Jun 29 04:15:14 localhost NetworkManager: <information>^IActivation (eth0) Stage 4 of 5 (IP Configure Timeout) scheduled...
Jun 29 04:15:14 localhost NetworkManager: <information>^IDHCP daemon state is now 14 (normal exit) for interface eth0
Jun 29 04:15:14 localhost NetworkManager: <information>^IDHCP daemon state is now 14 (normal exit) for interface eth0
Jun 29 04:15:14 localhost NetworkManager: <information>^IActivation (eth0) Stage 4 of 5 (IP Configure Timeout) started...
Jun 29 04:15:14 localhost NetworkManager: <information>^INo DHCP reply received. Automatically obtaining IP via Zeroconf.
Jun 29 04:15:14 localhost NetworkManager: <information>^Iautoip: Sending probe #0 for IP address 169.254.108.117.
Jun 29 04:15:14 localhost NetworkManager: <information>^Iautoip: Waiting for reply...

As you see, dhclient detects IP correctly (172.16.0.12), but NetworkManager fails to accept this IP and uses 169.254.108.117 instead. This results in non-working network connection, so I have to manually run dhclient and get a correct IP.

[Mark Reitblatt (mark-reitblatt)]

Interesting. Can you post a log of what happens when you run dhclient by hand?

[Evgeny Kuznetsov (nekr0z)]

Sure, but there's nothing unusual...

Aug 21 22:32:59 localhost dhclient: Internet Systems Consortium DHCP Client V3.0.3
Aug 21 22:32:59 localhost dhclient: Copyright 2004-2005 Internet Systems Consortium.
Aug 21 22:33:00 localhost dhclient: All rights reserved.
Aug 21 22:33:00 localhost dhclient: For info, please visit http://www.isc.org/products/DHCP
Aug 21 22:33:00 localhost dhclient:
Aug 21 22:33:01 localhost dhclient: Listening on LPF/eth1/00:0e:35:40:37:b6
Aug 21 22:33:01 localhost dhclient: Sending on LPF/eth1/00:0e:35:40:37:b6
Aug 21 22:33:01 localhost dhclient: Sending on Socket/fallback
Aug 21 22:33:01 localhost dhclient: DHCPREQUEST on eth1 to 255.255.255.255 port 67
Aug 21 22:33:01 localhost dhclient: DHCPACK from 192.168.0.1
Aug 21 22:33:01 localhost dhclient: bound to 192.168.0.138 -- renewal in 260 seconds.

(And it is the same ballpark for eth0 too.)

[Mark Reitblatt (mark-reitblatt)]

Could you please post it for eth0. You posted a log from each interface, but I'd like to see 2 logs from one.

[Evgeny Kuznetsov (nekr0z)]

You're welcome:

Aug 21 23:11:59 localhost dhclient: Internet Systems Consortium DHCP Client V3.0.3
Aug 21 23:11:59 localhost dhclient: Copyright 2004-2005 Internet Systems Consortium.
Aug 21 23:11:59 localhost dhclient: All rights reserved.
Aug 21 23:11:59 localhost dhclient: For info, please visit http://www.isc.org/products/DHCP
Aug 21 23:11:59 localhost dhclient:
Aug 21 23:12:00 localhost dhclient: Listening on LPF/eth0/00:0a:e4:26:b0:de
Aug 21 23:12:00 localhost dhclient: Sending on LPF/eth0/00:0a:e4:26:b0:de
Aug 21 23:12:00 localhost dhclient: Sending on Socket/fallback
Aug 21 23:12:03 localhost dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 4
Aug 21 23:12:03 localhost dhclient: DHCPOFFER from 192.168.0.1
Aug 21 23:12:03 localhost dhclient: DHCPREQUEST on eth0 to 255.255.255.255 port 67
Aug 21 23:12:04 localhost dhclient: DHCPACK from 192.168.0.1
Aug 21 23:12:04 localhost dhclient: bound to 192.168.0.4 -- renewal in 277 seconds.

[Mark Reitblatt (mark-reitblatt)]

Oh, you're on a different network now. I assume NetworkManager doesn't work on this network either? I thought you had one interface on each network, which is why I asked for the other log. Is this in Edgy?

[Evgeny Kuznetsov (nekr0z)]

Yes, I have moved, but I use the same router (changed numbers in fields to comply with the network). NetworkManager didn't work here, too (when I tried, and it was only once I moved in). Since that time I turned my Kubuntu Dapper into Ubuntu Dapper, but the problems stayed.

[Scott James Remnant (Canonical) (canonical-scott)]

Please confirm whether you are running dapper or edgy.

Also please attach the /etc/dhcp3/dhclient-script and /etc/dhcp3/dhclient-exit-hooks.d/dhcdbd file (or mention if either is missing)

[Evgeny Kuznetsov (nekr0z)]

I'm running Dapper, but...

As I am moving from KDE to GNOME now, I have installed network-manager-gnome yesterday (instead of knetworkmanager). There were also some updates, including kernel and stuff.

I'm proud to report that <b>the problem disappeared</b>. I didn't keep log of changes during my big update, so I cannot report which of the updates solved the problem, but no attempt to reproduce the problem succeeded.

As for me, the bug can be considered closed.