NetworkManager does not re-enable connection which was disabled because DHCP timed out

[Matti Laakso]

Binary package hint: network-manager

As requested by Mathieu Trudel in bug #274593, I'm opening a new bug.

If the DHCP server in the network goes down for some reason, NetworkManager marks the connection invalid once DHCP request times out:

Nov 8 10:59:19 lempo NetworkManager[975]: <warn> (eth0): DHCPv4 request timed out.
Nov 8 10:59:19 lempo NetworkManager[975]: <info> (eth0): canceled DHCP transaction, DHCP client pid 6586
Nov 8 10:59:19 lempo NetworkManager[975]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Timeout) scheduled...
Nov 8 10:59:19 lempo NetworkManager[975]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Timeout) started...
Nov 8 10:59:19 lempo NetworkManager[975]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled...
Nov 8 10:59:19 lempo NetworkManager[975]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Timeout) complete.
Nov 8 10:59:19 lempo NetworkManager[975]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) started...
Nov 8 10:59:19 lempo NetworkManager[975]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) failed (no IP configuration found)
Nov 8 10:59:19 lempo NetworkManager[975]: <info> (eth0): device state change: 7 -> 9 (reason 5)
Nov 8 10:59:19 lempo NetworkManager[975]: <info> Marking connection 'Auto eth0' invalid.
Nov 8 10:59:19 lempo NetworkManager[975]: <warn> Activation (eth0) failed.
Nov 8 10:59:19 lempo NetworkManager[975]: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete.
Nov 8 10:59:19 lempo NetworkManager[975]: <info> (eth0): device state change: 9 -> 3 (reason 0)
Nov 8 10:59:19 lempo NetworkManager[975]: <info> (eth0): deactivating device (reason: 0).

If I now unplug and replug the network cable (a common fix for network problems), NetworkManager does not try to get a new IP address via DHCP:

Nov 8 11:02:05 lempo NetworkManager[975]: <info> (eth0): carrier now OFF (device state 3)
Nov 8 11:02:05 lempo NetworkManager[975]: <info> (eth0): device state change: 3 -> 2 (reason 40)
Nov 8 11:02:05 lempo NetworkManager[975]: <info> (eth0): deactivating device (reason: 40).
Nov 8 11:02:07 lempo NetworkManager[975]: <info> (eth0): carrier now ON (device state 2)
Nov 8 11:02:07 lempo NetworkManager[975]: <info> (eth0): device state change: 2 -> 3 (reason 40)

Rather, I must log on to my computer, click on the nm-applet and select Auto eth0. This is highly inconvenient if I'm out of office and would like to do something remotely. Otherwise I could just ask my colleague to replug the cable.
---
Architecture: amd64
CRDA: Error: [Errno 2] No such file or directory
DistroRelease: Ubuntu 10.10
IfupdownConfig:
 auto lo
 iface lo inet loopback
IpRoute:
 130.233.174.128/27 dev eth0 proto kernel scope link src 130.233.174.133 metric 1
 192.168.122.0/24 dev virbr0 proto kernel scope link src 192.168.122.1
 169.254.0.0/16 dev eth0 scope link metric 1000
 default via 130.233.174.129 dev eth0 proto static
IwConfig:
 lo no wireless extensions.

 eth0 no wireless extensions.

 virbr0 no wireless extensions.
Keyfiles: Error: [Errno 2] No such file or directory
NonfreeKernelModules: nvidia
Package: network-manager 0.8.1+git.20100810t184654.ab580f4-0ubuntu2
PackageArchitecture: amd64
ProcVersionSignature: Ubuntu 2.6.35-22.35-generic 2.6.35.4
RfKill:

Tags: maverick
Uname: Linux 2.6.35-22-generic x86_64
UserGroups: adm admin cdrom dialout dip fax floppy fuse kvm libvirtd lpadmin plugdev sambashare tape video
WpaSupplicantLog:

[Matti Laakso (matti-laakso)]

Better yet, NM could automatically try to obtain a new IP periodically, like Windows does.

[Mathieu Trudel-Lapierre (cyphermox)]

Matti, NM already does that, through DHCP lease expiry.

Could you please run apport-collect for this bug so we can get all the relevant information for your system? We above all need to know which drivers you use so that those can be checked (since it's most likely more the driver not seeing the new carrier than NM not properly dealing with it).

You can do so quickly by running the command: apport-collect 672562

Thanks!

[Matti Laakso (matti-laakso)]

apport information

[Matti Laakso (matti-laakso)]

apport information

[Matti Laakso (matti-laakso)]

apport information

[Matti Laakso (matti-laakso)]

apport information

[Matti Laakso (matti-laakso)]

apport information

[Matti Laakso (matti-laakso)]

apport information

[Matti Laakso (matti-laakso)]

apport information

[Matti Laakso (matti-laakso)]

apport information

[Matti Laakso (matti-laakso)]

apport information

[Matti Laakso (matti-laakso)]

apport information

[Matti Laakso (matti-laakso)]

Looking at an older log (attached), where DHCP server went down on Nov 6, around 13:00, I see that NM tries to renew the lease at 13:09, 13:33 and 13:40, but then gives up and never tries again.

[Launchpad Janitor (janitor)]

[Expired for network-manager (Ubuntu) because there has been no activity for 60 days.]

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Mathieu Trudel-Lapierre (cyphermox)]

Triaged/Medium; assigned to myself to look into whether the carrier detection code does the right thing (which should be to try to re-establish connections, a *maybe* try connections that were previously failed).

[Matt Bush (mbbush)]

I had the same problem. After a network-wide power failure, my machine rebooted and requested an IP address at 12:08pm, and again at 12:09 but my sysadmin tells me that the DHCP server didn't complete its reboot until 12:10pm. At that point, network manager had already given up and deactivated eth0. I didn't have any connectivity at all until I came back into my office and clicked the "auto eth0" in the nm-applet GUI.

I've attached the syslog messages generated while network manager was trying to get an IP address.