NetworkManager

  1. Bug #1696415
  2. Comment #2

Comment 2 for bug 1696415

Revision history for this message
Sjors Gielen (sgielen) wrote : Re: NetworkManager seems to drop IPv4 DHCP lease even though it was successfully renewed

By setting log_level to DEBUG, I could confirm from the logs that there is a miscommunication between dhclient and NetworkManager causing this issue.

It looks like it is not NetworkManager that removes the IPv4 address from the interface; the address is removed from the interface automatically by the kernel because its lifetime expired:

jun 13 19:26:21 cuba NetworkManager[28642]: <debug> [1497374781.0763] platform: address: adding or updating IPv4 address: 192.168.0.55/24 lft 7200sec pref 7200sec lifetime 99735-0[7200,7200] dev 3 src unknown
jun 13 19:26:21 cuba NetworkManager[28642]: <debug> [1497374781.0763] platform: signal: address 4 changed: 192.168.0.55/24 lft 7200sec pref 7200sec lifetime 99735-99735[7200,7200] dev 3 src kernel
jun 13 21:26:21 cuba NetworkManager[28642]: <debug> [1497381981.3191] platform: signal: address 4 removed: 192.168.0.55/24 lft 0sec pref 0sec lifetime 106935-99735[7200,7200] dev 3 src kernel

The "address: adding or updating IPv4 address" message comes right after receiving a message from dhclient, because it sent a DHCPREQUEST and received a DHCPACK:

jun 13 19:26:21 cuba dhclient[13154]: DHCPREQUEST of 192.168.0.55 on eth1 to 192.168.0.3 port 67 (xid=0xfd7483b)
jun 13 19:26:21 cuba dhclient[13154]: DHCPACK of 192.168.0.55 from 192.168.0.3
jun 13 19:26:21 cuba NetworkManager[28642]: <debug> [1497374781.0748] bus-manager: (dhcp) accepted connection 0x7f9ae000fc60 on private socket
jun 13 19:26:21 cuba NetworkManager[28642]: <debug> [1497374781.0759] dhcp4 (eth1): DHCP reason 'RENEW' -> state 'bound'

Within the 2 hours lifetime of the IP address, another DHCPREQUEST & DHCPACK occurs, and some communication is attempted between dhclient and NetworkManager, but this doesn't result in the state change as seen above:

jun 13 20:20:11 cuba dhclient[13154]: DHCPREQUEST of 192.168.0.55 on eth1 to 192.168.0.3 port 67 (xid=0xfd7483b)
jun 13 20:20:11 cuba dhclient[13154]: DHCPACK of 192.168.0.55 from 192.168.0.3
jun 13 20:20:11 cuba NetworkManager[28642]: <debug> [1497378011.6527] bus-manager: (dhcp) accepted connection 0x7f9ae0019060 on private socket
jun 13 20:20:11 cuba NetworkManager[28642]: <debug> [1497378011.6527] bus-manager: (dhcp) closed connection 0x7f9ae0019060 on private socket
jun 13 20:20:11 cuba dhclient[13154]: bound to 192.168.0.55 -- renewal in 2731 seconds.

So, crucially, there is an attempted communication between dhclient and NetworkManager, but this doesn't result in an update to the lifetime of the IPv4 address. I'll focus my investigation on this. I would appreciate a reply from maintainers or upstream that they are aware of this issue.