NetworkManager interaction with dhclient triggers IP conflict detection at dhcp server, causes ip address changing every day

[Bast1aan]

After installing my laptop with Ubuntu and using the wired network cable with default NetworkManager service to handle the connection, I ran into the issue that my local ipv4 address changes every day, while this never happens for other devices in the network. This is undesirable to me, because it exhausts the local networks IP address pool and the change of IP is inconvenient when working with services like SSH, samba, etc. Added to this, I sometimes experience random network outages especially when waking up from suspend.

After some investigation, I found the following to happen:

- The exact time the DHCP server provides with a new IP address that different from previous one, is when I wake up my laptop after about 12 hours of being suspended, typicaly at the start of the new working day.
- When I lookup the logs of the DHCP server at the time of the laptop getting its new IP address, I find the following:
Sep 21 14:36 router dhcpd: DHCPDISCOVER from 68:f7:28:3f:a0:11 via eth2
Sep 21 14:36 router dhcpd: Abandoning IP address 192.168.1.137: pinged before offer
Sep 21 14:36 router dhcpd: DHCPDISCOVER from 68:f7:28:3f:a0:11 via eth2
Sep 21 14:36 router dhcpd: DHCPOFFER on 192.168.1.139 to 68:f7:28:3f:a0:11 (kubuntu1804) via eth2

It looks like the DHCP server is detecting a possible IP conflict because it can ping .137 while a DHCPDISCOVER for the hardware address matches the lease with the same IP address it is about to offer. To prevent problems, the DHCP server finds a new free IP address .139 and offers this one instead.

Why is this triggered by the ubuntu client? When I look at the client logs at the same time, I see following to happen:

Sep 21 00:27 kubuntu1804 systemd-sleep[21703]: Suspending system...
Sep 21 14:36 kubuntu1804 kernel: [14934.160293] Restarting tasks ... done.
Sep 21 14:36 kubuntu1804 NetworkManager[1027]: <info> [1537533403.1923] device (enp0s25): carrier: link connected
Sep 21 14:36 kubuntu1804 NetworkManager[1027]: <info> [1537533403.1925] device (enp0s25): DHCPv4 lease renewal requested
Sep 21 14:36 kubuntu1804 NetworkManager[1027]: <info> [1537533403.2246] dhcp4 (enp0s25): canceled DHCP transaction, DHCP client pid 18900
Sep 21 14:36 kubuntu1804 NetworkManager[1027]: <info> [1537533403.2247] dhcp4 (enp0s25): state changed bound -> done
Sep 21 14:36 kubuntu1804 NetworkManager[1027]: <info> [1537533403.2257] dhcp4 (enp0s25): activation: beginning transaction (timeout in 45 seconds)
Sep 21 14:36 kubuntu1804 NetworkManager[1027]: <info> [1537533403.2292] dhcp4 (enp0s25): dhclient started with pid 21860
Sep 21 14:36 kubuntu1804 dhclient[21860]: DHCPDISCOVER on enp0s25 to 255.255.255.255 port 67 interval 3 (xid=0x71ed8c51)
Sep 21 14:36 kubuntu1804 dhclient[21860]: DHCPDISCOVER on enp0s25 to 255.255.255.255 port 67 interval 5 (xid=0x71ed8c51)
Sep 21 14:36 kubuntu1804 dhclient[21860]: DHCPREQUEST of 192.168.1.139 on enp0s25 to 255.255.255.255 port 67 (xid=0x518ced71)
Sep 21 14:36 kubuntu1804 dhclient[21860]: DHCPOFFER of 192.168.1.139 from 192.168.1.1
Sep 21 14:36 kubuntu1804 dhclient[21860]: DHCPACK of 192.168.1.139 from 192.168.1.1

So if I understand it well, the summary of what happens here is:

1) Client wakes up after being suspended for about 14h
2) Existing running dhclient fired from NetworkManager discovers the lease has expired and requesting a renewal
3) Shortly after that this dhclient is killed by NetworkManager, probably because NetworkManager has detected a "link connected" event, caused by the suspend (the cable has not been removed physicaly). The old dhclient is killed during the lease renewal and probably long before the renewal procedure could be proparly handled
4) A new dhclient is fired by NetworkManager, performing a whole new DHCP request, getting a new IP address from the server

I expect the events 2 and 3 happening simultaneously are causing trouble. Probably the old IP .137 is already set to the interface while handling the lease renewal and then a new dhclient is started performing again a new DHCPREQUEST, confusing the dhcp server.

When I look at the ISC dhclient, it is running the hook script "/sbin/dhclient-script" when a lease is expired or the dhclient is terminated. See line 347 of this file:

    EXPIRE|FAIL|RELEASE|STOP)

        if [ -n "$old_ip_address" ]; then
            # flush leased IP
            ip -4 addr flush dev ${interface} label ${interface}
        fi

I see when dhclient is invoked by NetworkManager, the /sbin/dhclient-script hook is not run at all, but replaced by /usr/lib/NetworkManager/nm-dhcp-helper, fireing events to dbus. It is unclear for me if these events perform the correct actions like removing the old IP from the interface.

======================================================================================
Usual extra information:

1) Ubuntu version: Ubuntu 18.04.1 LTS

2) network-manager version: 1.10.6-2ubuntu1
   The DHCP server is a CentOS 7 machine running the ISC DHCP server version 4.2.5-68

3) What you expected to happen

the dhcp client of my machine is not causing the dhcp server to detect IP conflict and leasing a new IP every day, but keeps the same IP address for the hw address of the machine.

4) What happened instead

IP conflict is triggered by the DHCP server causing the IP of my machine to change every day

[Beniamino Galvani (bengal)]

Can you please file a bug on the upstream project tracker:

https://gitlab.freedesktop.org/NetworkManager/NetworkManager/issues

? Thanks.

[Till Kamppeter (till-kamppeter)]

Probably bug 1826403 is related. It got reported upstream as

https://gitlab.freedesktop.org/NetworkManager/NetworkManager/issues/166

Please check whether your bug is perhaps the same and comment on/follow the upstream bug.

[Brandon Applegate (vom)]

For what it's worth - I am seeing (I believe) this same issue on the latest Kali linux:

https://bugs.kali.org/view.php?id=7116

What's very interesting is that after this race condition happens, the machine still responds to the old IP yet it doesn't show with 'ip addr show'. Seems to be something down in the kernel that is still claiming this old IP.