[Touch-packages] [Bug 1696415] Re: NetworkManager does not update IPv4 address lifetime even though DHCP lease was successfully renewed
Hi Ray/Julian, > * NOTE: The final comment on the upstream GNOME bug claims that the fix > is incomplete. However, it is possible that the running NetworkManager was > not restarted (see Regression Potential notes above), which is why > nm-dhcp-helper is falling back to Event. This is not the case. Even today, one of the machines is showing the message from the wrapper that indicates the DHCP lease was not correctly applied according to the journal: ➜ sjors@cuba ~ cat /tmp/nm-helper-retries.log Tue Nov 14 07:23:07 CET 2017: needed 5 attempts to update NetworkManager (RENEW). Tue Nov 14 09:17:45 CET 2017: needed 5 attempts to update NetworkManager (RENEW). Tue Nov 14 10:06:58 CET 2017: needed 4 attempts to update NetworkManager (RENEW). This is even though the machine was rebooted yesterday, so the daemon was restarted: ➜ sjors@cuba ~ uptime 23:12:16 up 1 day, 14:04, 3 users, load average: 0,59, 0,49, 0,47 And the machine is using the patched version of the network-manager: ➜ sjors@cuba ~ apt-cache policy network-manager network-manager: Installed: 1.2.6-0ubuntu0.16.04.1screenpoint1 Candidate: 1.2.6-0ubuntu0.16.04.1screenpoint1 Version table: *** 1.2.6-0ubuntu0.16.04.1screenpoint1 100 100 /var/lib/dpkg/status 1.2.6-0ubuntu0.16.04.1 500 500 http://nl.archive.ubuntu.com/ubuntu xenial-updates/main amd64 Packages However, I have not investigated why this happens, as the wrapper script is an acceptable work-around. I'll report back, however, whether we still have this problem with the updated Xenial packages -- there is always a chance I made an error somewhere. -- You received this bug notification because you are a member of Ubuntu Touch seeded packages, which is subscribed to network-manager in Ubuntu. https://bugs.launchpad.net/bugs/1696415 Title: NetworkManager does not update IPv4 address lifetime even though DHCP lease was successfully renewed Status in NetworkManager: Confirmed Status in network-manager package in Ubuntu: Fix Released Status in network-manager source package in Xenial: In Progress Bug description: SRU REQUEST: Debdiff (nm-dhcp-helper.debdiff) attached. Fixed in current Ubuntu zesty and newer: Bionic uses NM 1.8.x. This bug was fixed upstream in 1.4. [Impact] * nm-dhcp-helper sometimes fails to notify NetworkManager of a DHCP lease renewal due to a DBus race condition. * Upstream NetworkManager 1.4 fixes the race condition by changing nm-dhcp-helper's DBus notification from signal "Event" to method "Notify". * Original bug submitter backported NM 1.4's nm-dhcp-helper notification fix to NM 1.2. This SRU request applies that backported patch to Xenial's NM 1.2.x. [Test Case] * Not reliably reproducible. Out of hundreds of machines, only a dozen or so fail to notify NetworkManager of a DHCP lease renewal about 30-50% of the time. (i.e. It's always the same handful of machines that fail.) * All such machines with the patched packages have been fine for weeks, over many dozens of lease renewals. [Regression Potential] * The patch changes both nm-dhcp-helper and NetworkManager itself. As soon as the new packages are unpacked, the new nm-dhcp-helper will be used on DHCP lease renewals, with the new Notify mechanism. Since the running, old NetworkManager is still expecting Event notifications, the patched nm-dhcp-helper has fallback capability to Event. * Once NetworkManager is restarted and is running the patched version, it will have the new Notify support. [Other Info] * Upstream bug w/ patch: https://bugzilla.gnome.org/show_bug.cgi?id=784636 * RHEL bug with links to the 1.4 commits from which the patch was derived: https://bugzilla.redhat.com/show_bug.cgi?id=1373276 * NOTE: The final comment on the upstream GNOME bug claims that the fix is incomplete. However, it is possible that the running NetworkManager was not restarted (see Regression Potential notes above), which is why nm-dhcp-helper is falling back to Event. The remainder of the log messages in that final comment are from a custom wrapper the submitter was running around nm-dhcp-helper. I have deployed the exact same patch (without said wrapper) to real-world systems and tested extensively, and see nothing but successful DHCP lease renewal notifications using D-Bus Notify, not D-Bus Event. I've found an issue on some of our Xenial office machines, causing NetworkManager to drop its IP address lease in some cases when it shouldn't. I'm not sure if the actual bug is in NetworkManager or perhaps dbus or dhclient, but I'll do my best to help to figure out where it is. What appears to happen: * NetworkManager is informed of a new IPv4 lease. * During the lease, dhclient keeps it fresh by renewing it using DHCPREQUESTs regularly. * In spite of this, NetworkManager drops the IP address from
[Touch-packages] [Bug 1696415] [NEW] NetworkManager seems to drop IPv4 DHCP lease even though it was successfully renewed
Public bug reported: I've found an issue on some of our Xenial office machines, causing NetworkManager to drop its IP address lease in some cases when it shouldn't. I'm not sure if the actual bug is in NetworkManager or perhaps dbus or dhclient, but I'll do my best to help to figure out where it is. What appears to happen: * NetworkManager is informed of a new IPv4 lease. * During the lease, dhclient keeps it fresh by renewing it using DHCPREQUESTs regularly. * In spite of this, NetworkManager drops the IP address from the interface when the last reported lease time expires. This happens on various machines, once every few days. We are using a failover DHCP configuration using two machines (192.168.0.3 'bonaire' and 192.168.0.4 'curacao'). The machine where I've done the debugging is called 'pampus' (192.168.0.166). As you can see in the logs, at 01:21:06 NetworkManager reports a new lease with lease time 7200. jun 07 01:21:06 pampus dhclient[1532]: DHCPREQUEST of 192.168.0.166 on eth0 to 192.168.0.4 port 67 (xid=0x3295b440) jun 07 01:21:06 pampus dhclient[1532]: DHCPACK of 192.168.0.166 from 192.168.0.4 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] address 192.168.0.166 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] plen 24 (255.255.255.0) jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] gateway 192.168.0.5 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] server identifier 192.168.0.4 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] lease time 7200 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] nameserver '192.168.0.3' jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] nameserver '192.168.0.4' jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] domain name 'office.screenpointmed.com' jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9531] dhcp4 (eth0): state changed bound -> bound After this, dhclient is supposed to keep the lease fresh, which it does. E.g. at 03:13:19 you can see a DHCPREQUEST and DHCPACK; I've seen this DHCPACK in a tcpdump and it contains a new lease time of 7200 seconds. jun 07 03:13:19 pampus dhclient[1532]: DHCPREQUEST of 192.168.0.166 on eth0 to 192.168.0.4 port 67 (xid=0x3295b440) jun 07 03:13:19 pampus dhclient[1532]: DHCPACK of 192.168.0.166 from 192.168.0.4 jun 07 03:13:19 pampus dhclient[1532]: bound to 192.168.0.166 -- renewal in 2708 seconds. However, at 03:21:07 (exactly 2 hours and 1 second after the last lease reported by NetworkManager) Avahi and NTP report that the IP address is gone: jun 07 03:21:07 pampus avahi-daemon[1167]: Withdrawing address record for 192.168.0.166 on eth0. jun 07 03:21:07 pampus avahi-daemon[1167]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.0.166. jun 07 03:21:07 pampus avahi-daemon[1167]: Interface eth0.IPv4 no longer relevant for mDNS. jun 07 03:21:08 pampus ntpd[18832]: Deleting interface #3 eth0, 192.168.0.166#123, interface stats: received=2512, sent=2549, dropped=0, active_time=111819 secs So I suspect NetworkManager dropped the IP address from the interface, because it wasn't informed by dhclient that the lease was renewed. The logs don't explicitly say this, so I may have to turn on more verbose debugging logs in NetworkManager or dhclient to verify this. ProblemType: Bug DistroRelease: Ubuntu 16.04 Package: network-manager 1.2.6-0ubuntu0.16.04.1 ProcVersionSignature: Ubuntu 4.4.0-66.87-generic 4.4.44 Uname: Linux 4.4.0-66-generic x86_64 NonfreeKernelModules: nvidia_uvm nvidia_drm nvidia_modeset nvidia ApportVersion: 2.20.1-0ubuntu2.6 Architecture: amd64 Date: Wed Jun 7 14:48:59 2017 IfupdownConfig: # interfaces(5) file used by ifup(8) and ifdown(8) auto lo iface lo inet loopback InstallationDate: Installed on 2016-11-04 (214 days ago) InstallationMedia: Ubuntu 14.04.5 LTS "Trusty Tahr" - Release amd64 (20160803) IpRoute: default via 192.168.0.5 dev eth0 proto static metric 100 192.168.0.0/24 dev eth0 proto kernel scope link src 192.168.0.166 192.168.0.0/24 dev eth0 proto kernel scope link src 192.168.0.166 metric 100 IwConfig: lono wireless extensions. eth1 no wireless extensions. eth0 no wireless extensions. NetworkManager.state: [main] NetworkingEnabled=true WirelessEnabled=true WWANEnabled=true WimaxEnabled=true RfKill: SourcePackage: network-manager UpgradeStatus: No upgrade log present (probably fresh install) nmcli-con: NAMEUUID TYPE TIMESTAMP TIMESTAMP-REALAUTOCONNECT AUTOCONNECT-PRIORITY READONLY DBUS-PATH ACTIVE DEVICE STATE ACTIVE-PATH Wired connection 1 37da1802-e1ce-3326-a6d0-f855cc32806d 802-3-ethernet 1496839466 wo 07 jun 2017 14:44:26 CEST yes 4294966297no /org/f
[Touch-packages] [Bug 1696415] 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]: [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]: [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]: [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]: [1497374781.0748] bus-manager: (dhcp) accepted connection 0x7f9ae000fc60 on private socket jun 13 19:26:21 cuba NetworkManager[28642]: [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]: [1497378011.6527] bus-manager: (dhcp) accepted connection 0x7f9ae0019060 on private socket jun 13 20:20:11 cuba NetworkManager[28642]: [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. -- You received this bug notification because you are a member of Ubuntu Touch seeded packages, which is subscribed to network-manager in Ubuntu. https://bugs.launchpad.net/bugs/1696415 Title: NetworkManager does not update IPv4 address lifetime even though DHCP lease was successfully renewed Status in network-manager package in Ubuntu: New Bug description: I've found an issue on some of our Xenial office machines, causing NetworkManager to drop its IP address lease in some cases when it shouldn't. I'm not sure if the actual bug is in NetworkManager or perhaps dbus or dhclient, but I'll do my best to help to figure out where it is. What appears to happen: * NetworkManager is informed of a new IPv4 lease. * During the lease, dhclient keeps it fresh by renewing it using DHCPREQUESTs regularly. * In spite of this, NetworkManager drops the IP address from the interface when the last reported lease time expires. This happens on various machines, once every few days. We are using a failover DHCP configuration using two machines (192.168.0.3 'bonaire' and 192.168.0.4 'curacao'). The machine where I've done the debugging is called 'pampus' (192.168.0.166). As you can see in the logs, at 01:21:06 NetworkManager reports a new lease with lease time 7200. jun 07 01:21:06 pampus dhclient[1532]: DHCPREQUEST of 192.168.0.166 on eth0 to 192.168.0.4 port 67 (xid=0x3295b440) jun 07 01:21:06 pampus dhclient[1532]: DHCPACK of 192.168.0.166 from 192.168.0.4 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] address 192.168.0.166 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] plen 24 (255.255.255.0) jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] gateway 192.168.0.5 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] server identifier 192.168.0.4 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] lease time 7200 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] nameserver '192.168.0.3' jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] nameserver '192.168.0.4' jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] domain name 'office.screenpointmed.com' jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9531] dhcp4 (eth0): state changed bound -> bound After this
[Touch-packages] [Bug 1696415] Re: NetworkManager does not update IPv4 address lifetime even though DHCP lease was successfully renewed
** Summary changed: - NetworkManager seems to drop IPv4 DHCP lease even though it was successfully renewed + NetworkManager does not update IPv4 address lifetime even though DHCP lease was successfully renewed -- You received this bug notification because you are a member of Ubuntu Touch seeded packages, which is subscribed to network-manager in Ubuntu. https://bugs.launchpad.net/bugs/1696415 Title: NetworkManager does not update IPv4 address lifetime even though DHCP lease was successfully renewed Status in network-manager package in Ubuntu: New Bug description: I've found an issue on some of our Xenial office machines, causing NetworkManager to drop its IP address lease in some cases when it shouldn't. I'm not sure if the actual bug is in NetworkManager or perhaps dbus or dhclient, but I'll do my best to help to figure out where it is. What appears to happen: * NetworkManager is informed of a new IPv4 lease. * During the lease, dhclient keeps it fresh by renewing it using DHCPREQUESTs regularly. * In spite of this, NetworkManager drops the IP address from the interface when the last reported lease time expires. This happens on various machines, once every few days. We are using a failover DHCP configuration using two machines (192.168.0.3 'bonaire' and 192.168.0.4 'curacao'). The machine where I've done the debugging is called 'pampus' (192.168.0.166). As you can see in the logs, at 01:21:06 NetworkManager reports a new lease with lease time 7200. jun 07 01:21:06 pampus dhclient[1532]: DHCPREQUEST of 192.168.0.166 on eth0 to 192.168.0.4 port 67 (xid=0x3295b440) jun 07 01:21:06 pampus dhclient[1532]: DHCPACK of 192.168.0.166 from 192.168.0.4 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] address 192.168.0.166 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] plen 24 (255.255.255.0) jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] gateway 192.168.0.5 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] server identifier 192.168.0.4 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] lease time 7200 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] nameserver '192.168.0.3' jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] nameserver '192.168.0.4' jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] domain name 'office.screenpointmed.com' jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9531] dhcp4 (eth0): state changed bound -> bound After this, dhclient is supposed to keep the lease fresh, which it does. E.g. at 03:13:19 you can see a DHCPREQUEST and DHCPACK; I've seen this DHCPACK in a tcpdump and it contains a new lease time of 7200 seconds. jun 07 03:13:19 pampus dhclient[1532]: DHCPREQUEST of 192.168.0.166 on eth0 to 192.168.0.4 port 67 (xid=0x3295b440) jun 07 03:13:19 pampus dhclient[1532]: DHCPACK of 192.168.0.166 from 192.168.0.4 jun 07 03:13:19 pampus dhclient[1532]: bound to 192.168.0.166 -- renewal in 2708 seconds. However, at 03:21:07 (exactly 2 hours and 1 second after the last lease reported by NetworkManager) Avahi and NTP report that the IP address is gone: jun 07 03:21:07 pampus avahi-daemon[1167]: Withdrawing address record for 192.168.0.166 on eth0. jun 07 03:21:07 pampus avahi-daemon[1167]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.0.166. jun 07 03:21:07 pampus avahi-daemon[1167]: Interface eth0.IPv4 no longer relevant for mDNS. jun 07 03:21:08 pampus ntpd[18832]: Deleting interface #3 eth0, 192.168.0.166#123, interface stats: received=2512, sent=2549, dropped=0, active_time=111819 secs So I suspect NetworkManager dropped the IP address from the interface, because it wasn't informed by dhclient that the lease was renewed. The logs don't explicitly say this, so I may have to turn on more verbose debugging logs in NetworkManager or dhclient to verify this. ProblemType: Bug DistroRelease: Ubuntu 16.04 Package: network-manager 1.2.6-0ubuntu0.16.04.1 ProcVersionSignature: Ubuntu 4.4.0-66.87-generic 4.4.44 Uname: Linux 4.4.0-66-generic x86_64 NonfreeKernelModules: nvidia_uvm nvidia_drm nvidia_modeset nvidia ApportVersion: 2.20.1-0ubuntu2.6 Architecture: amd64 Date: Wed Jun 7 14:48:59 2017 IfupdownConfig: # interfaces(5) file used by ifup(8) and ifdown(8) auto lo iface lo inet loopback InstallationDate: Installed on 2016-11-04 (214 days ago) InstallationMedia: Ubuntu 14.04.5 LTS "Trusty Tahr" - Release amd64 (20160803) IpRoute: default via 192.168.0.5 dev eth0 proto static metric 100 192.168.0.0/24 dev eth0 proto kernel scope link src 192.168.0.166 192.168.0.0/24 dev eth0 proto kernel scope link src 192.168.0.166 metric 100 IwConfig: lono wireless extensions. eth1 no wireless extensions. eth0 no wire
[Touch-packages] [Bug 1665264] Re: isc-dhcp-server 4.3.3-5ubuntu12.6 BOOTREPLY to wrong MAC address
Can confirm this with DHCP instead of BOOTP as well:
Apr 19 17:51:48 curacao dhcpd[18031]: reuse_lease: lease age 671 (secs) under
25% threshold, reply with unaltered, existing lease
Apr 19 17:51:48 curacao dhcpd[18031]: DHCPDISCOVER from 08:00:27:44:28:00 via
eth0
Apr 19 17:51:49 curacao dhcpd[18031]: DHCPOFFER on 192.168.0.60 to
08:00:27:04:2f:0f via eth0
Has this been reported upstream?
--
You received this bug notification because you are a member of Ubuntu
Touch seeded packages, which is subscribed to isc-dhcp in Ubuntu.
https://bugs.launchpad.net/bugs/1665264
Title:
isc-dhcp-server 4.3.3-5ubuntu12.6 BOOTREPLY to wrong MAC address
Status in isc-dhcp package in Ubuntu:
Confirmed
Bug description:
I am testing network boot on several embedded targets using BOOTP from
the isc-dhcp-server package using Ubuntu 16.04.2.
The /etc/dhcp/dhcpd.conf I modified looks like this:
subnet 192.168.3.0 netmask 255.255.255.0
{
# The filenames must correspond to the barebox and MLO files which are
placed in the /tftpboot directory
range dynamic-bootp 192.168.3.11 192.168.3.100;
if substring (option vendor-class-identifier, 0, 10) = "AM335x ROM"
{
filename "MLO";
}
elsif substring (option vendor-class-identifier, 0, 18) = "am335x
barebox-mlo"
{
filename "barebox.bin";
}
range 192.168.3.101 192.168.3.199;
}
Booting the first target does work out of the box with no issues:
Feb 16 09:11:38 lws- dhcpd[4259]: BOOTREPLY on 192.168.3.13 to
68:c9:0b:4a:3c:fe via enp5s2
Feb 16 09:11:46 lws- dhcpd[4259]: reuse_lease: lease age 63582 (secs)
under 25% th
Feb 16 09:11:46 lws- dhcpd[4259]: BOOTREQUEST from 68:c9:0b:1c:74:8c via
enp5s2
And then the booting works..
Trying to boot the second target (different board with different MAC)
does not work any more:
Feb 16 09:16:12 lws- dhcpd[4259]: BOOTREQUEST from 68:c9:0b:1c:74:8c via
enp5s2
Feb 16 09:16:12 lws- dhcpd[4259]: BOOTREPLY on 192.168.3.13 to
68:c9:0b:4a:3c:fe via enp5s2
The dhcp receives the request but replies to the MAC of the first
target. I see the same when trying the third, forth target and so on.
The dhcp always replies to the MAC of the first target.
This did work with the same configuration setup on Ubuntu 14.04.5 with
4.2.4-7ubuntu12.8.
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/isc-dhcp/+bug/1665264/+subscriptions
--
Mailing list: https://launchpad.net/~touch-packages
Post to : touch-packages@lists.launchpad.net
Unsubscribe : https://launchpad.net/~touch-packages
More help : https://help.launchpad.net/ListHelp
[Touch-packages] [Bug 1696415] Re: NetworkManager does not update IPv4 address lifetime even though DHCP lease was successfully renewed
I've closed down on the root cause being the /usr/lib/NetworkManager/nm-
dhcp-helper tool. Occasionally, this binary runs, but fails to correctly
send the update to NetworkManager. No errors occur when this happens;
NetworkManager in debug mode just says "accepted connection on private
socket" then "closed connection on private socket" without any updates
happening.
I've managed to work around the issue by wrapping
/usr/lib/NetworkManager/nm-dhcp-helper in a shell script that simply
performs the same lease update until the logs indicate that
NetworkManager received it. This doesn't fix the communication problem,
but adds a safety net that prevents the resulting issues. It's been
tested in an office network of some 12 PCs.
If anyone runs into this issue as well, run the following script to work
around it:
-8<-
#!/bin/bash
HELPERSCRIPT="/usr/lib/NetworkManager/nm-dhcp-helper"
HELPERBIN="/usr/lib/NetworkManager/nm-dhcp-helper.bin"
function is_elf() {
readelf -h "$1" >/dev/null 2>&1
if [ "$?" = "1" ]; then
echo "0"
else
echo "1"
fi
}
if [ "$(is_elf $HELPERSCRIPT)" = "1" ]; then
mv "$HELPERSCRIPT" "$HELPERBIN"
fi
cat <"$HELPERSCRIPT"
#!/usr/bin/perl
use strict;
use warnings;
if(\$< != 0) {
die "Must run as root\n";
}
my \$reason = \$ENV{reason} || "";
if(\$reason eq "PREINIT") {
# not lease information, so waiting for the journal will make
# nm-dhcp-helper wait for too long, just send it once and exit so
# dhclient will start to get a lease
system("${HELPERBIN}");
exit(0);
}
my \$attempts = 0;
my \$success = 0;
while(\$attempts < 10) {
\$attempts++;
my \$time = time();
sleep(1);
system("${HELPERBIN}");
sleep(1);
my \$leasetime = \`/bin/journalctl --since='\\@\$time' | grep
NetworkManager | grep ' lease time ' | wc -l\`;
if(\$leasetime == 1) {
\$success = 1;
last;
}
# Try again in 5 seconds
sleep(5);
}
if(\$attempts > 1) {
open my \$fh, ">>", "/tmp/nm-helper-retries.log" or die \$!;
my \$date = \`/bin/date\`;
1 while chomp \$date;
if(\$success) {
print \$fh "\$date: needed \$attempts attempts to update
NetworkManager (\$reason).\n";
} else {
print \$fh "\$date: gave up after \$attempts attempts
(\$reason).\n";
}
close \$fh;
}
exit(0);
EOF
chmod +x $HELPERSCRIPT
/usr/sbin/aa-complain /etc/apparmor.d/sbin.dhclient
--
You received this bug notification because you are a member of Ubuntu
Touch seeded packages, which is subscribed to network-manager in Ubuntu.
https://bugs.launchpad.net/bugs/1696415
Title:
NetworkManager does not update IPv4 address lifetime even though DHCP
lease was successfully renewed
Status in network-manager package in Ubuntu:
New
Bug description:
I've found an issue on some of our Xenial office machines, causing
NetworkManager to drop its IP address lease in some cases when it
shouldn't. I'm not sure if the actual bug is in NetworkManager or
perhaps dbus or dhclient, but I'll do my best to help to figure out
where it is.
What appears to happen:
* NetworkManager is informed of a new IPv4 lease.
* During the lease, dhclient keeps it fresh by renewing it using DHCPREQUESTs
regularly.
* In spite of this, NetworkManager drops the IP address from the interface
when the last reported lease time expires.
This happens on various machines, once every few days. We are using a
failover DHCP configuration using two machines (192.168.0.3 'bonaire'
and 192.168.0.4 'curacao').
The machine where I've done the debugging is called 'pampus'
(192.168.0.166). As you can see in the logs, at 01:21:06
NetworkManager reports a new lease with lease time 7200.
jun 07 01:21:06 pampus dhclient[1532]: DHCPREQUEST of 192.168.0.166 on eth0
to 192.168.0.4 port 67 (xid=0x3295b440)
jun 07 01:21:06 pampus dhclient[1532]: DHCPACK of 192.168.0.166 from
192.168.0.4
jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530]
address 192.168.0.166
jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] plen
24 (255.255.255.0)
jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530]
gateway 192.168.0.5
jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530]
server identifier 192.168.0.4
jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530]
lease time 7200
jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530]
nameserver '192.168.0.3'
jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530]
nameserver '192.168.0.4'
jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530]
domain name 'office.screenpointmed.com'
jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9531] dhcp4
(eth0): state changed bound -> bound
After this, dhclient is
[Touch-packages] [Bug 1696415] Re: NetworkManager does not update IPv4 address lifetime even though DHCP lease was successfully renewed
Hi Sebastien, thanks for your comment! I've reported the bug upstream as GNOME #784636, see https://bugzilla.gnome.org/show_bug.cgi?id=784636. I already added a bugwatch. ** Bug watch added: GNOME Bug Tracker #784636 https://bugzilla.gnome.org/show_bug.cgi?id=784636 ** Also affects: network-manager via https://bugzilla.gnome.org/show_bug.cgi?id=784636 Importance: Unknown Status: Unknown -- You received this bug notification because you are a member of Ubuntu Touch seeded packages, which is subscribed to network-manager in Ubuntu. https://bugs.launchpad.net/bugs/1696415 Title: NetworkManager does not update IPv4 address lifetime even though DHCP lease was successfully renewed Status in NetworkManager: Unknown Status in network-manager package in Ubuntu: New Bug description: I've found an issue on some of our Xenial office machines, causing NetworkManager to drop its IP address lease in some cases when it shouldn't. I'm not sure if the actual bug is in NetworkManager or perhaps dbus or dhclient, but I'll do my best to help to figure out where it is. What appears to happen: * NetworkManager is informed of a new IPv4 lease. * During the lease, dhclient keeps it fresh by renewing it using DHCPREQUESTs regularly. * In spite of this, NetworkManager drops the IP address from the interface when the last reported lease time expires. This happens on various machines, once every few days. We are using a failover DHCP configuration using two machines (192.168.0.3 'bonaire' and 192.168.0.4 'curacao'). The machine where I've done the debugging is called 'pampus' (192.168.0.166). As you can see in the logs, at 01:21:06 NetworkManager reports a new lease with lease time 7200. jun 07 01:21:06 pampus dhclient[1532]: DHCPREQUEST of 192.168.0.166 on eth0 to 192.168.0.4 port 67 (xid=0x3295b440) jun 07 01:21:06 pampus dhclient[1532]: DHCPACK of 192.168.0.166 from 192.168.0.4 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] address 192.168.0.166 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] plen 24 (255.255.255.0) jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] gateway 192.168.0.5 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] server identifier 192.168.0.4 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] lease time 7200 jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] nameserver '192.168.0.3' jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] nameserver '192.168.0.4' jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9530] domain name 'office.screenpointmed.com' jun 07 01:21:06 pampus NetworkManager[1161]: [1496791266.9531] dhcp4 (eth0): state changed bound -> bound After this, dhclient is supposed to keep the lease fresh, which it does. E.g. at 03:13:19 you can see a DHCPREQUEST and DHCPACK; I've seen this DHCPACK in a tcpdump and it contains a new lease time of 7200 seconds. jun 07 03:13:19 pampus dhclient[1532]: DHCPREQUEST of 192.168.0.166 on eth0 to 192.168.0.4 port 67 (xid=0x3295b440) jun 07 03:13:19 pampus dhclient[1532]: DHCPACK of 192.168.0.166 from 192.168.0.4 jun 07 03:13:19 pampus dhclient[1532]: bound to 192.168.0.166 -- renewal in 2708 seconds. However, at 03:21:07 (exactly 2 hours and 1 second after the last lease reported by NetworkManager) Avahi and NTP report that the IP address is gone: jun 07 03:21:07 pampus avahi-daemon[1167]: Withdrawing address record for 192.168.0.166 on eth0. jun 07 03:21:07 pampus avahi-daemon[1167]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.0.166. jun 07 03:21:07 pampus avahi-daemon[1167]: Interface eth0.IPv4 no longer relevant for mDNS. jun 07 03:21:08 pampus ntpd[18832]: Deleting interface #3 eth0, 192.168.0.166#123, interface stats: received=2512, sent=2549, dropped=0, active_time=111819 secs So I suspect NetworkManager dropped the IP address from the interface, because it wasn't informed by dhclient that the lease was renewed. The logs don't explicitly say this, so I may have to turn on more verbose debugging logs in NetworkManager or dhclient to verify this. ProblemType: Bug DistroRelease: Ubuntu 16.04 Package: network-manager 1.2.6-0ubuntu0.16.04.1 ProcVersionSignature: Ubuntu 4.4.0-66.87-generic 4.4.44 Uname: Linux 4.4.0-66-generic x86_64 NonfreeKernelModules: nvidia_uvm nvidia_drm nvidia_modeset nvidia ApportVersion: 2.20.1-0ubuntu2.6 Architecture: amd64 Date: Wed Jun 7 14:48:59 2017 IfupdownConfig: # interfaces(5) file used by ifup(8) and ifdown(8) auto lo iface lo inet loopback InstallationDate: Installed on 2016-11-04 (214 days ago) InstallationMedia: Ubuntu 14.04.5 LTS "Trusty Tahr" - Release amd64 (20160803) IpRoute: default via 192.168.0.5 dev eth0 proto static metric 100 192.168.0.0/24 dev eth0 proto kernel
