Created attachment 1673917 [details] Log with enabled debug and traces Description of problem: NetworkManager drops connection and immediately reconnects every few minutes. This affects both Wi-Fi and Ethernet connections. Version-Release number of selected component (if applicable): NetworkManager-1.22.10-1.fc32.x86_64 How reproducible: Always after upgrading to Fedora 32 from Fedora 31. On two systems with completely different hardware: laptop (Wi-Fi) and desktop (Ethernet). Steps to Reproduce: 1. Upgrade from Fedora 31 to Fedora 32 beta. (not tried on fresh install) 2. Connect to wired or wireless network. Actual results: Connection drops every few minutes, then NetworkManager reconnects again. Expected results: Connection should be stable. Additional info: See attached log file. There are suspicious messages like following: ... Mar 27 05:03:57 im-mac NetworkManager[8942]: <error> [1585267437.9657] dhcp4 (wlp3s0): error -113 dispatching events Mar 27 05:03:57 im-mac NetworkManager[8942]: <info> [1585267437.9657] dhcp4 (wlp3s0): state changed bound -> fail Mar 27 05:03:57 im-mac NetworkManager[8942]: <debug> [1585267437.9658] device[8f6e8f7151f43c0b] (wlp3s0): new DHCPv4 client state 6 Mar 27 05:03:57 im-mac NetworkManager[8942]: <debug> [1585267437.9658] device[8f6e8f7151f43c0b] (wlp3s0): DHCPv4 failed (ip_state done, was_active 0) Mar 27 05:03:57 im-mac NetworkManager[8942]: <info> [1585267437.9659] device (wlp3s0): DHCPv4: trying to acquire a new lease within 90 seconds Mar 27 05:03:57 im-mac NetworkManager[8942]: <trace> [1585267437.9659] dbus-object[f294c400c57033b2]: unexport: "/org/freedesktop/NetworkManager/DHCP4Config/9" Mar 27 05:03:57 im-mac NetworkManager[8942]: <trace> [1585267437.9661] dbus-object[7b670322338bce53]: export: "/org/freedesktop/NetworkManager/DHCP4Config/10" Mar 27 05:04:22 im-mac NetworkManager[8942]: <debug> [1585267462.5780] device[8f6e8f7151f43c0b] (wlp3s0): wifi-scan: scanning requested but not allowed at this time Mar 27 05:04:22 im-mac NetworkManager[8942]: <debug> [1585267462.5782] device[8f6e8f7151f43c0b] (wlp3s0): wifi-scan: scheduled in 43 seconds (interval now 43 seconds) Mar 27 05:05:05 im-mac NetworkManager[8942]: <debug> [1585267505.5821] device[8f6e8f7151f43c0b] (wlp3s0): wifi-scan: scanning requested but not allowed at this time Mar 27 05:05:05 im-mac NetworkManager[8942]: <debug> [1585267505.5821] device[8f6e8f7151f43c0b] (wlp3s0): wifi-scan: scheduled in 43 seconds (interval now 43 seconds) Mar 27 05:05:26 im-mac NetworkManager[8942]: <trace> [1585267526.5757] settings: [timestamps-keyfile]: updated entry for timestamps.ef34d972-9aa4-4b09-841f-bcd1b4ae09c9 Mar 27 05:05:26 im-mac NetworkManager[8942]: <trace> [1585267526.5758] settings: [timestamps-keyfile]: schedule flushing changes to disk Mar 27 05:05:26 im-mac NetworkManager[8942]: <trace> [1585267526.5867] settings: [timestamps-keyfile]: write keyfile: "/var/lib/NetworkManager/timestamps" Mar 27 05:05:28 im-mac NetworkManager[8942]: <info> [1585267528.5749] device (wlp3s0): DHCPv4: grace period expired Mar 27 05:05:28 im-mac NetworkManager[8942]: <trace> [1585267528.5750] device[8f6e8f7151f43c0b] (wlp3s0): ip4-state: set to 4 (fail) Mar 27 05:05:28 im-mac NetworkManager[8942]: <info> [1585267528.5750] device (wlp3s0): state change: activated -> failed (reason 'ip-config-unavailable', sys-iface-state: 'managed') ... This looks like a bug in NetworkManager's own DHCP client. Everything works fine when using dhclient. Workaround: Just add [main] dhcp=dhclient into NM's configuration (/etc/NetworkManager/conf.d/use-dhclient.conf for example), and then restart NetworkManager.service.
Hi, the failure happens when the client tries to renew the address using unicast UDP. The client successfully sends a REQUEST but then receives error EHOSTUNREACH, perhaps during a recvmsg(). This should not happen, so I wonder if there is anything special in your setup. Mar 27 04:40:35 im-mac NetworkManager[8942]: <debug> [1585266035.5267] dhcp4 (wlp3s0): send REQUEST of 192.168.42.245 to 192.168.42.2 Mar 27 04:40:35 im-mac NetworkManager[8942]: <error> [1585266035.5367] dhcp4 (wlp3s0): error -113 dispatching events Mar 27 04:40:35 im-mac NetworkManager[8942]: <info> [1585266035.5368] dhcp4 (wlp3s0): state changed bound -> fail Would you be able to capture a packet trace? You can use this command, after the wifi device is connected: tcpdump -i wlp3s0 -w dhcp.pcap udp port 67 or icmp Then wait 6 minutes - the device should disconnect - and then attach the dhcp.pcap. If you could also provide the trace for dhcp=dhclient, that would be very useful. Thank you!
I can comfirm that this happens to me as well on Fedora 32. Very frustrating! All these weeks I was thinking it was my router acting up. Thanks for the workaround Ivan! Apr 30 22:33:15 inspiron NetworkManager[1432]: <info> [1588300395.4681] dhcp4 (wlp2s0): state changed bound -> expire Apr 30 22:33:15 inspiron NetworkManager[1432]: <info> [1588300395.4685] device (wlp2s0): DHCPv4: trying to acquire a new lease within 90 seconds Apr 30 22:33:16 inspiron avahi-daemon[1297]: Withdrawing address record for 192.168.0.2 on wlp2s0. Apr 30 22:33:16 inspiron avahi-daemon[1297]: Leaving mDNS multicast group on interface wlp2s0.IPv4 with address 192.168.0.2. Apr 30 22:33:16 inspiron avahi-daemon[1297]: Interface wlp2s0.IPv4 no longer relevant for mDNS. Apr 30 22:34:45 inspiron NetworkManager[1432]: <info> [1588300485.8778] device (wlp2s0): DHCPv4: grace period expired Apr 30 22:34:45 inspiron NetworkManager[1432]: <info> [1588300485.8780] device (wlp2s0): state change: activated -> failed (reason 'ip-config-unavailable', > Apr 30 22:34:45 inspiron NetworkManager[1432]: <info> [1588300485.8804] manager: NetworkManager state is now DISCONNECTED Apr 30 22:34:45 inspiron NetworkManager[1432]: <warn> [1588300485.8850] device (wlp2s0): Activation: failed for connection 'MyWifi' Apr 30 22:34:45 inspiron NetworkManager[1432]: <info> [1588300485.8893] device (wlp2s0): state change: failed -> disconnected (reason 'none', sys-iface-stat> Apr 30 22:34:45 inspiron avahi-daemon[1297]: Withdrawing address record for ::300:4kii:rff4:cc on wlp2s0. Apr 30 22:34:45 inspiron avahi-daemon[1297]: Leaving mDNS multicast group on interface wlp2s0.IPv6 with address ::300:4kii:rff4:cc. Apr 30 22:34:45 inspiron avahi-daemon[1297]: Joining mDNS multicast group on interface wlp2s0.IPv6 with address fe80::300:4kii:rff4:cc. Apr 30 22:34:45 inspiron avahi-daemon[1297]: Registering new address record for fe80::300:4kii:rff4:cc on wlp2s0.*. Apr 30 22:34:45 inspiron avahi-daemon[1297]: Withdrawing address record for fe80::300:4kii:rff4:cc on wlp2s0. Apr 30 22:34:45 inspiron avahi-daemon[1297]: Leaving mDNS multicast group on interface wlp2s0.IPv6 with address fe80::300:4kii:rff4:cc. Apr 30 22:34:45 inspiron avahi-daemon[1297]: Interface wlp2s0.IPv6 no longer relevant for mDNS. Apr 30 22:34:45 inspiron systemd[1]: Starting Network Manager Script Dispatcher Service... Apr 30 22:34:45 inspiron NetworkManager[1432]: <info> [1588300485.8997] dhcp4 (wlp2s0): canceled DHCP transaction Apr 30 22:34:45 inspiron NetworkManager[1432]: <info> [1588300485.8998] dhcp4 (wlp2s0): state changed expire -> done Apr 30 22:34:45 inspiron kernel: wlp2s0: deauthenticating from 98:da:c4:a2:a2:a2 by local choice (Reason: 3=DEAUTH_LEAVING) Apr 30 22:34:45 inspiron systemd[1]: Started Network Manager Script Dispatcher Service. Apr 30 22:34:45 inspiron audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=NetworkManager-dispatc> Apr 30 22:34:45 inspiron wpa_supplicant[1547]: wlp2s0: CTRL-EVENT-DISCONNECTED bssid=98:da:c4:a2:a2:a2 reason=3 locally_generated=1 Apr 30 22:34:45 inspiron wpa_supplicant[1547]: dbus: wpa_dbus_property_changed: no property SessionLength in object /fi/w1/wpa_supplicant1/Interfaces/0 Apr 30 22:34:45 inspiron NetworkManager[1432]: <info> [1588300485.9131] device (wlp2s0): set-hw-addr: set MAC address to ab:ba:7B:ed:ac:6C (scanning) Apr 30 22:34:45 inspiron NetworkManager[1432]: <warn> [1588300485.9199] sup-iface[0x562bce8af120,wlp2s0]: connection disconnected (reason -3) Apr 30 22:34:45 inspiron NetworkManager[1432]: <info> [1588300485.9200] device (wlp2s0): supplicant interface state: completed -> disconnected Apr 30 22:34:45 inspiron NetworkManager[1432]: <info> [1588300485.9200] device (p2p-dev-wlp2s0): supplicant management interface state: completed -> disconn> Apr 30 22:34:45 inspiron chronyd[1362]: Source 108.59.2.24 offline I will try to do the capture and post it here. This seems to happen right after the dhcp lease is about to expire, I'll just shorten the length of the lease. The router I'm connected to is wirelessly bridged to the one that is acting as a dhcp server btw. Intel wireless 3165 but also happens via ethernet as well (Realtek RTL8107E). Ethernet never reconnects though while wifi reconnects in a couple of minutes/seconds usually.
Created attachment 1683562 [details] tcpdump for dhcp Attached the tcpdump. Also, I can confirm Ivan's workaround solves the problem.
It think this is duplicate of bug 1829178 (technically, this rhbz is older, but still. Doesn't really matter which is the duplicate). In particular the > <error> [1585267437.9657] dhcp4 (wlp3s0): error -113 dispatching events message. This should be fixed https://gitlab.freedesktop.org/NetworkManager/NetworkManager/-/commit/c5d1d4c498c50dfc7d2d18b213a117dd1199f1de, which was backported and released as 1.22.12. It should thus be fixed on Fedora 32 with package NetworkManager-1.22.12-1.fc32. Closing as duplicate. *** This bug has been marked as a duplicate of bug 1829178 ***