Public bug reported:
Hello,
Network manager resets IP address every 30 minutes (perhaps this time depends
on default-lease-time)
This issue affects at least the latest package Network Manager in Ubuntu
20.04.2 - network-manager 1.22.10-1ubuntu2.2.
It seems this issue has been occuring more than a year (perhaps from release
Ubuntu 20.04) and is not fixed yet.
It is possible that this issue occurs only with our dhcp server. We have not
checked if the issue occurs with other dhcp servers.
----
lsb_release -rd
Description: Ubuntu 20.04.2 LTS
Release: 20.04
----
apt-cache policy network-manager
network-manager:
Installed: 1.22.10-1ubuntu2.2
Candidate: 1.22.10-1ubuntu2.2
Version table:
*** 1.22.10-1ubuntu2.2 500
500 http://ua.archive.ubuntu.com/ubuntu focal-updates/main amd64
Packages
100 /var/lib/dpkg/status
1.22.10-1ubuntu1 500
500 http://ua.archive.ubuntu.com/ubuntu focal/main amd64 Packages
-----
STR:
Install Ubuntu 20.04.2 (update if needed) and connect to network with dhcp
server.
AR:
Connection drops every few minutes, then NetworkManager reconnects again.
On screen we can see message "Network disconnect" and right away "Network
connect"
ER:
Connection should be stable.
We have found the similar bug here -
https://bugzilla.redhat.com/show_bug.cgi?id=1817788
It is possible that in my case the root of issue is the same and the isue is
fixed in network manager 1.22.12
We need a new networkmanager package in Ubuntu 20.04 repository which
has not got this bug.
There is a part of /var/log/syslog
Here we can see error "error -113 dispatching events"
----
Jun 16 16:01:40 user-System-Product-Name NetworkManager[589]: <debug>
[1623848500.8092] dhcp4 (enp3s0): send REQUEST of 192.168.61.156 to 192.168.61.2
Jun 16 16:01:40 user-System-Product-Name NetworkManager[589]: <error>
[1623848500.8225] dhcp4 (enp3s0): error -113 dispatching events
Jun 16 16:01:40 user-System-Product-Name NetworkManager[589]: <info>
[1623848500.8226] dhcp4 (enp3s0): state changed bound -> fail
Jun 16 16:01:40 user-System-Product-Name NetworkManager[589]: <debug>
[1623848500.8226] device[5565e4c243c020e9] (enp3s0): new DHCPv4 client state 6
Jun 16 16:01:40 user-System-Product-Name NetworkManager[589]: <debug>
[1623848500.8227] device[5565e4c243c020e9] (enp3s0): DHCPv4 failed (ip_state
done, was_active 0)
Jun 16 16:01:40 user-System-Product-Name NetworkManager[589]: <info>
[1623848500.8228] device (enp3s0): DHCPv4: trying to acquire a new lease within
90 seconds
Jun 16 16:01:40 user-System-Product-Name NetworkManager[589]: <trace>
[1623848500.8228] dbus-object[cffc3e670403e5f9]: unexport:
"/org/freedesktop/NetworkManager/DHCP4Config/8"
Jun 16 16:01:40 user-System-Product-Name NetworkManager[589]: <trace>
[1623848500.8232] dbus-object[e4f7ca28a56cb5dc]: export:
"/org/freedesktop/NetworkManager/DHCP4Config/9"
Jun 16 16:02:18 user-System-Product-Name NetworkManager[589]: <trace>
[1623848538.4785] device[5565e4c243c020e9] (enp3s0): connectivity: [IPv6]
periodic-check: re-scheduled in 299970 milliseconds (300 se
conds interval)
Jun 16 16:02:18 user-System-Product-Name NetworkManager[589]: <trace>
[1623848538.4787] device[5565e4c243c020e9] (enp3s0): connectivity: [IPv6] start
check (seq:86, periodic-check)
Jun 16 16:02:18 user-System-Product-Name NetworkManager[589]: <debug>
[1623848538.4790] connectivity: (enp3s0,IPv6,86) start request to
'http://connectivity-check.ubuntu.com/' (try resolving 'connectivit
y-check.ubuntu.com' using systemd-resolved)
Jun 16 16:02:18 user-System-Product-Name NetworkManager[589]: <debug>
[1623848538.4833] connectivity: (enp3s0,IPv6,86) can't resolve a name via
systemd-resolved: GDBus.Error:org.freedesktop.resolve1.NoSu
chRR: 'connectivity-check.ubuntu.com' does not have any RR of the requested type
Jun 16 16:02:18 user-System-Product-Name systemd-resolved[549]: Server returned
error NXDOMAIN, mitigating potential DNS violation DVE-2018-0001, retrying
transaction with reduced feature level UDP.
Jun 16 16:02:18 user-System-Product-Name systemd-resolved[549]: message
repeated 2 times: [ Server returned error NXDOMAIN, mitigating potential DNS
violation DVE-2018-0001, retrying transaction with reduced feature level UDP.]
Jun 16 16:02:18 user-System-Product-Name NetworkManager[589]: <debug>
[1623848538.4903] connectivity: (enp3s0,IPv6,86) check completed: LIMITED;
check failed: (6) Couldn't resolve host name
Jun 16 16:02:18 user-System-Product-Name NetworkManager[589]: <trace>
[1623848538.4904] device[5565e4c243c020e9] (enp3s0): connectivity: [Ipv6]
complete check (seq:86, state:LIMITED)
Jun 16 16:02:18 user-System-Product-Name NetworkManager[589]: <trace>
[1623848538.4904] device[5565e4c243c020e9] (enp3s0): connectivity: [IPv6]
periodic-check: re-scheduled in 299958 milliseconds (300 seconds interval)
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <info>
[1623848591.1502] device (enp3s0): DHCPv4: grace period expired
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <trace>
[1623848591.1504] device[5565e4c243c020e9] (enp3s0): ip4-state: set to 4 (fail)
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <info>
[1623848591.1505] device (enp3s0): state change: activated -> failed (reason
'ip-config-unavailable', sys-iface-state: 'managed')
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1505] device[5565e4c243c020e9] (enp3s0): add_pending_action (1):
'in-state-change'
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <trace>
[1623848591.1506] device[5565e4c243c020e9] (enp3s0): stable-id: clear
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1519] active-connection[0x55e541f60b50]: set state deactivated (was
activated)
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <info>
[1623848591.1522] manager: NetworkManager state is now DISCONNECTED
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1526] active-connection[0x55e541f60b50]: check-master-ready: not
signalling (state deactivated, no master)
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <trace>
[1623848591.1526] settings: [timestamps-keyfile]: updated entry for
timestamps.10bc9efc-52ea-3b01-9f83-9a74d08f5bd8
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <trace>
[1623848591.1527] settings: [timestamps-keyfile]: schedule flushing changes to
disk
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1540] policy: connection 'Wired connection 1' failed to
autoconnect; 3 tries left
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <trace>
[1623848591.1547]
settings-connection[f4ee5bd504ea46ff,10bc9efc-52ea-3b01-9f83-9a74d08f5bd8]:
autoconnect: retries set 3
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <trace>
[1623848591.1557] settings: update[10bc9efc-52ea-3b01-9f83-9a74d08f5bd8]:
clear-secrets: update profile "Wired connection 1" (not persisted)
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <trace>
[1623848591.1561] settings:
storage[10bc9efc-52ea-3b01-9f83-9a74d08f5bd8,573139a81fd7e45b/keyfile]: change
event with connection "Wired connection 1" (file
"/run/NetworkManager/system-connections/Wired connection 1.nmconnection")
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <trace>
[1623848591.1562] settings: update[10bc9efc-52ea-3b01-9f83-9a74d08f5bd8]:
updating connection "Wired connection 1" (573139a81fd7e45b/keyfile)
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1575] manager: ActivatingConnection now (none)
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <warn>
[1623848591.1578] device (enp3s0): Activation: failed for connection 'Wired
connection 1'
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1579] device[5565e4c243c020e9] (enp3s0): add_pending_action (2):
'queued-state-change-disconnected'
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1579] device[5565e4c243c020e9] (enp3s0): queue-state[disconnected,
reason:none, id:2599]: queue state change
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1580] dispatcher: (26) (enp3s0) dispatching action 'down'
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <trace>
[1623848591.1591] device[5565e4c243c020e9] (enp3s0): connectivity: [IPv4]
periodic-check: re-scheduled in 1000 milliseconds (1 seconds interval)
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <trace>
[1623848591.1591] device[5565e4c243c020e9] (enp3s0): connectivity: [IPv4] start
check (seq:87, periodic-check)
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1592] connectivity: (enp3s0,IPv4,87) start request to
'http://connectivity-check.ubuntu.com/' (try resolving
'connectivity-check.ubuntu.com' using systemd-resolved)
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <trace>
[1623848591.1592] device[5565e4c243c020e9] (enp3s0): connectivity: [IPv6]
periodic-check: re-scheduled in 1000 milliseconds (1 seconds interval)
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <trace>
[1623848591.1592] device[5565e4c243c020e9] (enp3s0): connectivity: [IPv6] start
check (seq:88, periodic-check)
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1593] connectivity: (enp3s0,IPv6,88) start request to
'http://connectivity-check.ubuntu.com/' (try resolving
'connectivity-check.ubuntu.com' using systemd-resolved)
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1593] device[5565e4c243c020e9] (enp3s0): remove_pending_action (1):
'in-state-change'
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <trace>
[1623848591.1593] dbus-object[9fb423193bf9dee7]: unexport:
"/org/freedesktop/NetworkManager/ActiveConnection/3"
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1595] device[5565e4c243c020e9] (enp3s0): add_pending_action (2):
'autoactivate'
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1595] device[5565e4c243c020e9] (enp3s0): queue-state[disconnected,
reason:none, id:2599]: change state
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <info>
[1623848591.1595] device (enp3s0): state change: failed -> disconnected (reason
'none', sys-iface-state: 'managed')
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1595] device[5565e4c243c020e9] (enp3s0): add_pending_action (3):
'in-state-change'
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1595] device[5565e4c243c020e9] (enp3s0): will enable userland IPv6LL
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1595] platform-linux: link: change 2: user-ipv6ll: set IPv6 address
generation mode to none
Jun 16 16:03:11 user-System-Product-Name avahi-daemon[585]: Withdrawing address
record for fe80::fe2b:7dec:f6dd:866a on enp3s0.
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1601] platform-linux: do-request-link: 2
Jun 16 16:03:11 user-System-Product-Name avahi-daemon[585]: Leaving mDNS
multicast group on interface enp3s0.IPv6 with address fe80::fe2b:7dec:f6dd:866a.
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <trace>
[1623848591.1601] platform-linux: event-notification: RTM_NEWLINK, flags 0, seq
0: 2: enp3s0 <UP,LOWER_UP;broadcast,multicast,up,running,lowerup> mtu 1500 arp
1 ethernet? not-init addrgenmode none addr 50:46:5D:B6:95:FE brd
FF:FF:FF:FF:FF:FF rx:29522,30613975 tx:10473,1099746
Jun 16 16:03:11 user-System-Product-Name avahi-daemon[585]: Interface
enp3s0.IPv6 no longer relevant for mDNS.
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1602] platform: (enp3s0) signal: link changed: 2: enp3s0
<UP,LOWER_UP;broadcast,multicast,up,running,lowerup> mtu 1500 arp 1 ethernet?
init addrgenmode none addr 50:46:5D:B6:95:FE brd FF:FF:FF:FF:FF:FF driver r8169
rx:29522,30613975 tx:10473,1099746
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1602] device[5565e4c243c020e9] (enp3s0): queued link change for
ifindex 2
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <trace>
[1623848591.1602] platform-linux: event-notification: RTM_NEWLINK, flags 0, seq
103: 2: enp3s0 <UP,LOWER_UP;broadcast,multicast,up,running,lowerup> mtu 1500
arp 1 ethernet? not-init addrgenmode none addr 50:46:5D:B6:95:FE brd
FF:FF:FF:FF:FF:FF rx:29522,30613975 tx:10473,1099746
Jun 16 16:03:11 user-System-Product-Name NetworkManager[589]: <debug>
[1623848591.1603] platform-linux: do-change-link[2]: success changing link:
success
----
We are attaching tcpdump file for investigation.
Here client sent a request and server answered with ACK. It seem that client
failed on the ACK and after 90 seconds client sent a new request.
** Affects: network-manager (Ubuntu)
Importance: Undecided
Status: New
** Attachment added: "dhcp01.pcap"
https://bugs.launchpad.net/bugs/1932291/+attachment/5505243/+files/dhcp01.pcap
--
You received this bug notification because you are a member of Ubuntu
Bugs, which is subscribed to Ubuntu.
https://bugs.launchpad.net/bugs/1932291
Title:
dhcp client resets IP address every few minutes
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/network-manager/+bug/1932291/+subscriptions
--
ubuntu-bugs mailing list
ubuntu-bugs@lists.ubuntu.com
https://lists.ubuntu.com/mailman/listinfo/ubuntu-bugs
