[Bug 1551351] Re: dhclient does not renew leases

Tue Nov 8 08:14:49 UTC 2016

It happens to me after recent updates in 16.04 LTS. On boot I get an IP
from the DHCP server, all is well, but the IP is dropped after a while,
without complaint from network manager applet which still shows like the
network is connected. Unplugging and plugging the ethernet cable solves
the problem for the whole day. Looking in the syslog it appears that
NetworkManager is started at boot time and then systemd tries to start
it again, causing an IP conflict:

Nov  8 09:45:14 floring-desktop NetworkManager[1611]: <info>  [1478591114.2788] device (eth0): link disconnected (deferring action for 4 seconds)
Nov  8 09:45:14 floring-desktop kernel: [ 1906.680617] tg3 0000:03:00.0 eth0: Link is down
Nov  8 09:45:16 floring-desktop kernel: [ 1908.580879] tg3 0000:03:00.0 eth0: Link is up at 100 Mbps, full duplex
Nov  8 09:45:16 floring-desktop kernel: [ 1908.580885] tg3 0000:03:00.0 eth0: Flow control is on for TX and on for RX
Nov  8 09:45:16 floring-desktop kernel: [ 1908.580888] tg3 0000:03:00.0 eth0: EEE is disabled
Nov  8 09:45:16 floring-desktop NetworkManager[1611]: <info>  [1478591116.1791] device (eth0): link connected
Nov  8 09:45:16 floring-desktop NetworkManager[1611]: <info>  [1478591116.1792] device (eth0): DHCPv4 lease renewal requested
Nov  8 09:45:16 floring-desktop NetworkManager[1611]: <info>  [1478591116.1954] dhcp4 (eth0): canceled DHCP transaction, DHCP client pid 1915
Nov  8 09:45:16 floring-desktop NetworkManager[1611]: <info>  [1478591116.1954] dhcp4 (eth0): state changed bound -> done
Nov  8 09:45:16 floring-desktop NetworkManager[1611]: <info>  [1478591116.1960] dhcp4 (eth0): activation: beginning transaction (timeout in 45 seconds)
Nov  8 09:45:16 floring-desktop NetworkManager[1611]: <info>  [1478591116.2110] dhcp4 (eth0): dhclient started with pid 6862
Nov  8 09:45:16 floring-desktop dhclient[6862]: DHCPREQUEST of 10.4.0.227 on eth0 to 255.255.255.255 port 67 (xid=0x2ec87280)
Nov  8 09:45:16 floring-desktop dhclient[6862]: DHCPACK of 10.4.0.227 from 10.4.0.1
Nov  8 09:45:16 floring-desktop NetworkManager[1611]: <info>  [1478591116.2735]   address 10.4.0.227
Nov  8 09:45:16 floring-desktop NetworkManager[1611]: <info>  [1478591116.2736]   plen 24 (255.255.255.0)
Nov  8 09:45:16 floring-desktop NetworkManager[1611]: <info>  [1478591116.2736]   gateway 10.4.0.1
Nov  8 09:45:16 floring-desktop NetworkManager[1611]: <info>  [1478591116.2736]   server identifier 10.4.0.1
Nov  8 09:45:16 floring-desktop avahi-daemon[1280]: Joining mDNS multicast group on interface eth0.IPv4 with address 10.4.0.227.
Nov  8 09:45:16 floring-desktop NetworkManager[1611]: <info>  [1478591116.2736]   lease time 600
[...]
Nov  8 09:45:16 floring-desktop NetworkManager[1611]: <info>  [1478591116.2737] dhcp4 (eth0): state changed unknown -> bound
Nov  8 09:45:16 floring-desktop avahi-daemon[1280]: New relevant interface eth0.IPv4 for mDNS.
Nov  8 09:45:16 floring-desktop avahi-daemon[1280]: Registering new address record for 10.4.0.227 on eth0.IPv4.
Nov  8 09:45:16 floring-desktop NetworkManager[1611]: <info>  [1478591116.2765] policy: set 'Wired connection 1' (eth0) as default for IPv4 routing and DNS
Nov  8 09:45:16 floring-desktop dbus[1301]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Nov  8 09:45:16 floring-desktop systemd[1]: Starting Network Manager Script Dispatcher Service...
Nov  8 09:45:16 floring-desktop dhclient[6862]: bound to 10.4.0.227 -- renewal in 279 seconds.
Nov  8 09:45:16 floring-desktop dbus[1301]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Nov  8 09:45:16 floring-desktop systemd[1]: Started Network Manager Script Dispatcher Service.
Nov  8 09:45:16 floring-desktop nm-dispatcher: req:1 'dhcp4-change' [eth0]: new request (1 scripts)
Nov  8 09:45:16 floring-desktop nm-dispatcher: req:1 'dhcp4-change' [eth0]: start running ordered scripts...
Nov  8 09:45:16 floring-desktop whoopsie[1270]: [09:45:16] online
Nov  8 09:45:17 floring-desktop nimDNSResponder: mDNSCoreReceiveResponse: Received from 10.4.0.227:5353   23 227.0.4.10.in-addr.arpa. PTR floring-desktop.local.
Nov  8 09:45:17 floring-desktop nimDNSResponder: mDNSCoreReceiveResponse: Unexpected conflict discarding   25 227.0.4.10.in-addr.arpa. PTR floring-desktop-2.local.
Nov  8 09:49:56 floring-desktop dhclient[6862]: DHCPREQUEST of 10.4.0.227 on eth0 to 10.4.0.1 port 67 (xid=0x2ec87280)
Nov  8 09:49:56 floring-desktop dhclient[6862]: DHCPACK of 10.4.0.227 from 10.4.0.1
Nov  8 09:49:56 floring-desktop NetworkManager[1611]: <info>  [1478591396.0689]   address 10.4.0.227
[...]
Nov  8 09:49:56 floring-desktop NetworkManager[1611]: <info>  [1478591396.0691] dhcp4 (eth0): state changed bound -> bound
Nov  8 09:49:56 floring-desktop dbus[1301]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Nov  8 09:49:56 floring-desktop systemd[1]: Starting Network Manager Script Dispatcher Service...
Nov  8 09:49:56 floring-desktop dbus[1301]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Nov  8 09:49:56 floring-desktop systemd[1]: Started Network Manager Script Dispatcher Service.
Nov  8 09:49:56 floring-desktop nm-dispatcher: req:1 'dhcp4-change' [eth0]: new request (1 scripts)
Nov  8 09:49:56 floring-desktop nm-dispatcher: req:1 'dhcp4-change' [eth0]: start running ordered scripts...
Nov  8 09:49:56 floring-desktop dhclient[6862]: bound to 10.4.0.227 -- renewal in 246 seconds.
Nov  8 09:49:57 floring-desktop nimDNSResponder: mDNSCoreReceiveResponse: Received from 10.4.0.227:5353   23 227.0.4.10.in-addr.arpa. PTR floring-desktop.local.
Nov  8 09:49:57 floring-desktop nimDNSResponder: mDNSCoreReceiveResponse: Unexpected conflict discarding   25 227.0.4.10.in-addr.arpa. PTR floring-desktop-2.local.
Nov  8 09:51:04 floring-desktop NetworkManager[1611]: <warn>  [1478591464.7538] device (eth0): disconnecting connection 'Wired connection 1' for new activation request.
Nov  8 09:51:04 floring-desktop NetworkManager[1611]: <info>  [1478591464.7539] device (eth0): state change: activated -> deactivating (reason 'new-activation') [100 110 60]
Nov  8 09:51:04 floring-desktop NetworkManager[1611]: <info>  [1478591464.7540] manager: NetworkManager state is now DISCONNECTING
Nov  8 09:51:04 floring-desktop whoopsie[1270]: [09:51:04] offline
Nov  8 09:51:04 floring-desktop NetworkManager[1611]: <info>  [1478591464.8347] device (eth0): disconnecting for new activation request.
Nov  8 09:51:04 floring-desktop NetworkManager[1611]: <info>  [1478591464.8349] audit: op="connection-activate" uuid="b21315e5-8e76-3dec-9d35-2763b820d454" name="Wired connection 1" pid=4154 uid=1000 result="success"
Nov  8 09:51:04 floring-desktop NetworkManager[1611]: <info>  [1478591464.8357] device (eth0): state change: deactivating -> disconnected (reason 'new-activation') [110 30 60]
Nov  8 09:51:04 floring-desktop avahi-daemon[1280]: Withdrawing address record for fe80::5ebc:9f2d:3673:65d4 on eth0.

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to isc-dhcp in Ubuntu.
https://bugs.launchpad.net/bugs/1551351

Title:
  dhclient does not renew leases

Status in bind9 package in Ubuntu:
  Fix Released
Status in isc-dhcp package in Ubuntu:
  Fix Released
Status in bind9 source package in Xenial:
  Fix Released
Status in isc-dhcp source package in Xenial:
  Fix Released

Bug description:
  Release: Xenial

  I think this only recently started after some bind9 updates triggered a rebuild. When booting dhclient gets started and acquires an IP address, but it does seem to lock up somewhere as it does not renew the lease.
  In my environment I set the lease time to 5 minutes, so I notice such things rather soon. I looked on the dhcp server side but saw any further dhcp messages come in from the client side.

  Related bugs:
   * bug 1551415:  systemctl stop networking hang / timeout 

  ProblemType: Bug
  DistroRelease: Ubuntu 16.04
  Package: isc-dhcp-client 4.3.3-5ubuntu8
  ProcVersionSignature: Ubuntu 4.4.0-9.24-generic 4.4.3
  Uname: Linux 4.4.0-9-generic x86_64
  ApportVersion: 2.20-0ubuntu3
  Architecture: amd64
  Date: Mon Feb 29 12:32:52 2016
  DhclientLeases:

  SourcePackage: isc-dhcp
  UpgradeStatus: No upgrade log present (probably fresh install)

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/bind9/+bug/1551351/+subscriptions