Adding syslog file ** Attachment added: "syslog.bz2" https://bugs.launchpad.net/ubuntu/+source/network-manager/+bug/1932291/+attachment/5505262/+files/syslog.bz2
** Description changed: 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 + 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. -- 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 [email protected] https://lists.ubuntu.com/mailman/listinfo/ubuntu-bugs
