Dynamic Host Configuration Protocol (DHCP) interface fails to renew IP address after system time changes.

Solution In Progress - Updated -

Environment

  • Red Hat Enterprise Linux (RHEL) 7

Issue

  • DHCP address fails to renew IP address after system time changes.

  • NetworkManager interface using DHCP losing connectivity with no obvious cause noted in syslog other than some services logging the device is no longer active.

    avahi-daemon[1349]: Withdrawing address record for X.X.X.X on enp3s0.
avahi-daemon[1349]: Leaving mDNS multicast group on interface enp3s0.IPv4 with address X.X.X.X.
avahi-daemon[1349]: Interface enp3s0.IPv4 no longer relevant for mDNS.
ntpd[1376]: Deleting interface #2 enp3s0, X.X.X.X#123, interface stats: received=1187, sent=1187, dropped=0, active_time=7200 secs

Resolution

Update to dhcp-4.2.5-79.el7 (or higher) which was made available via RHBA-2020:1087

Work-Around

Root Cause

When the system time changes after dhclient has obtained a DHCP lease, dhclient may fail to renew the lease and just silently let the lease expire.

Diagnostic Steps

While the clock may be changed for a variety of reason, here is an example of the issue seen 1 hour (DHCP lease time) after a reboot. The issue in this case is triggered due to the hardware clock being off by 5 hours (18,000 seconds) and ntpd correcting the situation once the system is on the network via DHCP address. Here are some things to note in the following syslog output.

  1. Sep 30 21:47:07 - 'lease time 3600' indicates that dhclient needs to renew IP address in 1 hour. But since ntpd needs networking up before it can set the proper time this is really occurring at 13:47:07
  2. Sep 30 13:47:12 - 'clock_step -28799.303930 s' is ntpd adjusting the time backwards 5 hours
  3. Sep 30 14:47:10 - 'Deleting interface .* active_time=3599 secs' is ntpd reacting to the IP being removed from the interface. As you can see this occurs 1 hour after obtaining the initial lease that was good for 1 hour / 3600 seconds as noted in #1 above. Furthermore, ntpd conviently logs fact that interface was active 3599 seconds, which is just 1 second less than how long lease was valid.
Sep 30 21:47:07 rhel7-0 NetworkManager[783]: <info> dhclient started with pid 1527
Sep 30 21:47:07 rhel7-0 NetworkManager[783]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Sep 30 21:47:07 rhel7-0 NetworkManager[783]: <info> (eth0): DHCPv4 state changed nbi -> preinit
Sep 30 21:47:07 rhel7-0 NetworkManager[783]: <info> (eth0): DHCPv4 state changed preinit -> bound
Sep 30 21:47:07 rhel7-0 NetworkManager[783]: <info>   address 192.168.122.53
Sep 30 21:47:07 rhel7-0 NetworkManager[783]: <info>   plen 24 (255.255.255.0)
Sep 30 21:47:07 rhel7-0 NetworkManager[783]: <info>   gateway 192.168.122.1
Sep 30 21:47:07 rhel7-0 NetworkManager[783]: <info>   server identifier 192.168.122.1
Sep 30 21:47:07 rhel7-0 NetworkManager[783]: <info>   lease time 3600
Sep 30 21:47:07 rhel7-0 NetworkManager[783]: <info>   hostname 'rhel7-0'
Sep 30 21:47:07 rhel7-0 NetworkManager[783]: <info>   nameserver '192.168.122.1'
Sep 30 21:47:07 rhel7-0 NetworkManager[783]: <info>   domain name 'localdomain'
<snip>
Sep 30 21:47:11 rhel7-0 dracut: *** Including module: network ***
Sep 30 13:47:12 rhel7-0 ntpd[653]: 0.0.0.0 c61c 0c clock_step -28799.303930 s
Sep 30 13:47:12 rhel7-0 systemd: Time has been changed
<snip>
Sep 30 14:47:10 rhel7-0 ntpd[653]: Deleting interface #4 eth0, 192.168.122.53#123, interface stats: received=98, sent=98, dropped=0, active_time=3599 secs
Sep 30 14:47:10 rhel7-0 ntpd[653]: 172.31.0.2 interface 192.168.122.53 -> (none)
Sep 30 14:47:10 rhel7-0 ntpd[653]: 172.31.0.1 interface 192.168.122.53 -> (none)

This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.

Comments