Description of problem: TBH I am not sure if this is a NetworkManager problem or a bug in some other component like dnsmasq. I'm on x86-64 Fedora 24, Lenovo Yoga. Before a recent "dnf update", this machine worked perfectly. After the update, NetworkManager can no longer connect to my home wifi router. There have been no router configuration changes. What I see is that Networkmanager attempts to connect. However the icon in the gnome shell remains a question mark. I looked at /var/log/messages a bit (I will append some relevant logs) and noticed that it was failing to look up "http://fedoraproject.org/static/hotspot.txt". If I edit /etc/resolv.conf to add a working nameserver, then my network connection starts working. Logs from the most recent failure, hopefully this is helpful: Sep 20 09:52:58 bapiya NetworkManager[808]: <info> [1474386778.1896] manager: NetworkManager state is now CONNECTED_GLOBAL Sep 20 10:10:55 bapiya NetworkManager[808]: <info> [1474387855.2930] manager: sleep requested (sleeping: no enabled: yes) Sep 20 10:10:55 bapiya NetworkManager[808]: <info> [1474387855.2934] manager: sleeping... Sep 20 10:10:55 bapiya NetworkManager[808]: <info> [1474387855.2934] manager: NetworkManager state is now ASLEEP Sep 20 10:10:55 bapiya NetworkManager[808]: <info> [1474387855.2939] device (wlp0s26u1u4i2): state change: activated -> deactivating (reason 'sleeping') [100 110 37] Sep 20 10:10:55 bapiya NetworkManager[808]: <info> [1474387855.3162] device (wlp0s26u1u4i2): state change: deactivating -> disconnected (reason 'sleeping') [110 30 37] Sep 20 10:10:55 bapiya avahi-daemon[693]: Leaving mDNS multicast group on interface wlp0s26u1u4i2.IPv6 with address fe80::2ed0:5aff:fede:c3ba. Sep 20 10:10:55 bapiya avahi-daemon[693]: Interface wlp0s26u1u4i2.IPv6 no longer relevant for mDNS. Sep 20 10:10:55 bapiya NetworkManager[808]: <info> [1474387855.3475] dhcp4 (wlp0s26u1u4i2): canceled DHCP transaction, DHCP client pid 19883 Sep 20 10:10:55 bapiya dnsmasq[1628]: setting upstream servers from DBus Sep 20 10:10:55 bapiya NetworkManager[808]: <info> [1474387855.3475] dhcp4 (wlp0s26u1u4i2): state changed bound -> done Sep 20 10:10:55 bapiya dnsmasq[1568]: reading /etc/resolv.conf Sep 20 10:10:55 bapiya avahi-daemon[693]: Leaving mDNS multicast group on interface wlp0s26u1u4i2.IPv4 with address 192.168.0.5. Sep 20 10:10:55 bapiya dnsmasq[1568]: using nameserver 127.0.0.1#53 Sep 20 10:10:55 bapiya avahi-daemon[693]: Interface wlp0s26u1u4i2.IPv4 no longer relevant for mDNS. Sep 20 10:10:55 bapiya dnsmasq[1628]: cleared cache Sep 20 10:10:55 bapiya NetworkManager[808]: <warn> [1474387855.3779] sup-iface[0x55be0c4994e0,wlp0s26u1u4i2]: connection disconnected (reason -3) Sep 20 10:10:55 bapiya NetworkManager[808]: <info> [1474387855.3781] device (wlp0s26u1u4i2): supplicant interface state: completed -> disconnected Sep 20 10:10:55 bapiya NetworkManager[808]: <info> [1474387855.3787] device (wlp0s26u1u4i2): state change: disconnected -> unmanaged (reason 'sleeping') [30 10 37] Sep 20 10:25:20 bapiya NetworkManager[808]: <error> [1474388720.8546] platform-linux: do-change-link[68]: failure changing link: failure 19 (No such device) Sep 20 10:25:20 bapiya NetworkManager[808]: <warn> [1474388720.8614] device (wlp0s26u1u4i2): failed to disable userspace IPv6LL address handling Sep 20 10:25:20 bapiya NetworkManager[808]: <info> [1474388720.8789] radio killswitch /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.4/1-1.4:1.2/ieee80211/phy64/rfkill131 disappeared Sep 20 10:25:21 bapiya NetworkManager[808]: <info> [1474388721.0418] manager: wake requested (sleeping: yes enabled: yes) Sep 20 10:25:21 bapiya NetworkManager[808]: <info> [1474388721.0419] manager: waking up... Sep 20 10:25:21 bapiya NetworkManager[808]: <info> [1474388721.0419] manager: NetworkManager state is now CONNECTED_LOCAL Sep 20 10:25:21 bapiya NetworkManager[808]: <info> [1474388721.0492] connectivity: check for uri 'http://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname' Sep 20 10:25:21 bapiya NetworkManager[808]: <info> [1474388721.5895] (wlan0): using nl80211 for WiFi device control Sep 20 10:25:21 bapiya NetworkManager[808]: <info> [1474388721.5906] manager: (wlan0): new 802.11 WiFi device (/org/freedesktop/NetworkManager/Devices/68) Sep 20 10:25:21 bapiya NetworkManager[808]: <info> [1474388721.6193] device (wlan0): interface index 69 renamed iface from 'wlan0' to 'wlp0s26u1u4i2' Sep 20 10:25:21 bapiya NetworkManager[808]: <info> [1474388721.6323] device (wlp0s26u1u4i2): state change: unmanaged -> unavailable (reason 'managed') [10 20 2] Sep 20 10:25:21 bapiya NetworkManager[808]: <info> [1474388721.6461] (wlp0s26u1u4i2): using nl80211 for WiFi device control Sep 20 10:25:21 bapiya NetworkManager[808]: <info> [1474388721.6655] rfkill133: found WiFi radio killswitch (at /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.4/1-1.4:1.2/ieee80211/phy65/rfkill133) (driver rtl8xxxu) Sep 20 10:25:21 bapiya NetworkManager[808]: <info> [1474388721.6823] sup-iface[0x55be0c55bad0,wlp0s26u1u4i2]: supports 4 scan SSIDs Sep 20 10:25:21 bapiya NetworkManager[808]: <info> [1474388721.6837] device (wlp0s26u1u4i2): supplicant interface state: starting -> ready Sep 20 10:25:21 bapiya NetworkManager[808]: <info> [1474388721.6838] device (wlp0s26u1u4i2): state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42] Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4336] device (wlp0s26u1u4i2): supplicant interface state: ready -> inactive Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4563] policy: auto-activating connection 'recherche' Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4574] device (wlp0s26u1u4i2): Activation: starting connection 'recherche' (2fd9a90b-465f-4738-83f4-639ea756bb69) Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4580] device (wlp0s26u1u4i2): state change: disconnected -> prepare (reason 'none') [30 40 0] Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4586] manager: NetworkManager state is now CONNECTING Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4597] device (wlp0s26u1u4i2): state change: prepare -> config (reason 'none') [40 50 0] Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4606] device (wlp0s26u1u4i2): Activation: (wifi) access point 'recherche' has security, but secrets are required. Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4612] device (wlp0s26u1u4i2): state change: config -> need-auth (reason 'none') [50 60 0] Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4756] device (wlp0s26u1u4i2): state change: need-auth -> prepare (reason 'none') [60 40 0] Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4789] device (wlp0s26u1u4i2): state change: prepare -> config (reason 'none') [40 50 0] Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4796] device (wlp0s26u1u4i2): Activation: (wifi) connection 'recherche' has security, and secrets exist. No new secrets needed. Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4811] Config: added 'ssid' value 'recherche' Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4815] Config: added 'scan_ssid' value '1' Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4818] Config: added 'key_mgmt' value 'WPA-PSK' Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4820] Config: added 'psk' value '<omitted>' Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.4823] Config: added 'proto' value 'WPA RSN' Sep 20 10:25:22 bapiya NetworkManager[808]: <info> [1474388722.5529] sup-iface[0x55be0c55bad0,wlp0s26u1u4i2]: config: set interface ap_scan to 1 Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.2185] device (wlp0s26u1u4i2): supplicant interface state: inactive -> authenticating Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.2314] device (wlp0s26u1u4i2): supplicant interface state: authenticating -> associating Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.2345] device (wlp0s26u1u4i2): supplicant interface state: associating -> associated Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.2436] device (wlp0s26u1u4i2): supplicant interface state: associated -> 4-way handshake Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.2651] device (wlp0s26u1u4i2): supplicant interface state: 4-way handshake -> completed Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.2652] device (wlp0s26u1u4i2): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'recherche'. Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.2859] device (wlp0s26u1u4i2): state change: config -> ip-config (reason 'none') [50 70 0] Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.2864] dhcp4 (wlp0s26u1u4i2): activation: beginning transaction (timeout in 45 seconds) Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.2898] dhcp4 (wlp0s26u1u4i2): dhclient started with pid 24868 Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3372] address 192.168.0.5 Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3372] plen 24 (255.255.255.0) Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3373] gateway 192.168.0.1 Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3373] server identifier 192.168.0.1 Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3373] lease time 86400 Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3373] nameserver '192.168.0.1' Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3373] nameserver '205.171.2.25' Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3374] domain name 'Home' Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3374] dhcp4 (wlp0s26u1u4i2): state changed unknown -> bound Sep 20 10:25:23 bapiya avahi-daemon[693]: Joining mDNS multicast group on interface wlp0s26u1u4i2.IPv4 with address 192.168.0.5. Sep 20 10:25:23 bapiya avahi-daemon[693]: New relevant interface wlp0s26u1u4i2.IPv4 for mDNS. Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3432] device (wlp0s26u1u4i2): state change: ip-config -> ip-check (reason 'none') [70 80 0] Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3660] device (wlp0s26u1u4i2): state change: ip-check -> secondaries (reason 'none') [80 90 0] Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3663] device (wlp0s26u1u4i2): state change: secondaries -> activated (reason 'none') [90 100 0] Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3664] manager: NetworkManager state is now CONNECTED_LOCAL Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3841] manager: NetworkManager state is now CONNECTED_SITE Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3843] policy: set 'recherche' (wlp0s26u1u4i2) as default for IPv4 routing and DNS Sep 20 10:25:23 bapiya dnsmasq[1568]: reading /etc/resolv.conf Sep 20 10:25:23 bapiya dnsmasq[1568]: using nameserver 127.0.0.1#53 Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.3866] device (wlp0s26u1u4i2): Activation: successful, device activated. Sep 20 10:25:23 bapiya dnsmasq[1628]: setting upstream servers from DBus Sep 20 10:25:23 bapiya dnsmasq[1628]: using nameserver 192.168.0.1#53(via wlp0s26u1u4i2) Sep 20 10:25:23 bapiya dnsmasq[1628]: using nameserver 205.171.2.25#53(via wlp0s26u1u4i2) Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.4090] connectivity: check for uri 'http://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname' Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.4096] connectivity: check for uri 'http://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname' Sep 20 10:25:23 bapiya dnsmasq[1628]: cleared cache Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.4160] connectivity: check for uri 'http://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname' Sep 20 10:25:23 bapiya NetworkManager[808]: <info> [1474388723.4161] connectivity: check for uri 'http://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname' Sep 20 10:25:24 bapiya avahi-daemon[693]: Joining mDNS multicast group on interface wlp0s26u1u4i2.IPv6 with address fe80::2ed0:5aff:fede:c3ba. Sep 20 10:25:24 bapiya avahi-daemon[693]: New relevant interface wlp0s26u1u4i2.IPv6 for mDNS. Sep 20 10:30:24 bapiya NetworkManager[808]: <info> [1474389024.1110] connectivity: check for uri 'http://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname'
Hi, can you please try this (as root): nmcli general logging level KEEP domains DNS:TRACE echo log-queries > /etc/NetworkManager/dnsmasq.d/log-queries killall -HUP NetworkManager then connect to the wifi network, check that you don't have connectivity and run: dig fedoraproject.org @127.0.0.1 and paste the output, as well as logs from /var/log/messages (or if you prefer from 'journalctl -u NetworkManager -e'). Thanks! Does the issue go away if you run 'killall -HUP NetworkManager' after establishing the wifi connection?
(In reply to Beniamino Galvani from comment #1) > Hi, can you please try this (as root): > > nmcli general logging level KEEP domains DNS:TRACE > echo log-queries > /etc/NetworkManager/dnsmasq.d/log-queries > killall -HUP NetworkManager > > then connect to the wifi network I did these steps. To connect to the wifi network, I used the gnome-shell menu to disable wifi, then re-enabled it. > Does the issue go away if you run 'killall -HUP NetworkManager' after > establishing the wifi connection? Yes, this makes it work. I will attach the requested log momentarily. The "dig" command worked fine after the killall. However if I close the laptop and reopen it (causing the failure again) it says: ; <<>> DiG 9.10.4-P2-RedHat-9.10.4-1.P2.fc24 <<>> fedoraproject.org @127.0.0.1 ;; global options: +cmd ;; Got answer: ;; ->>HEADER<<- opcode: QUERY, status: REFUSED, id: 33659 ;; flags: qr rd ra ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0 ;; QUESTION SECTION: ;fedoraproject.org. IN A ;; Query time: 0 msec ;; SERVER: 127.0.0.1#53(127.0.0.1) ;; WHEN: Wed Sep 21 09:36:31 MDT 2016 ;; MSG SIZE rcvd: 35
Created attachment 1203375 [details] journalctl -u NetworkManager -e
Hi, now I understand; the wireless NIC is a USB one and when the system is suspended and resumed an interface with a different ifindex appears. This triggers a known issue in dnsmasq related to wrong caching of socket descriptors. We observed this issue only with VPNs connection before, but apparently it can also happen with wifi. Upstream dnsmasq already includes a fix for this bug, while the Fedora package still lacks it and needs a backport. In the meanwhile you can use this workaround: cat <<'EOF' > /etc/NetworkManager/dispatcher.d/99-dnsmasq-restart.sh #!/bin/sh [ "$2" = up ] && killall -HUP NetworkManager exit 0 EOF chmod +x /etc/NetworkManager/dispatcher.d/99-dnsmasq-restart.sh See bugs 1373485 (Fedora) and 1367772 (RHEL) for more details. *** This bug has been marked as a duplicate of bug 1373485 ***
Thank you very much. I appreciate your quick response and analysis of this.
FWIW the workaround in comment #4 doesn't work for me; but doing killall -HUP manually does.