WiFi fails to resume after suspend; Race with wpasupplicant / wpa_cli resume?

Bug #1556357 reported by Haw Loeung on 2016-03-12
292
This bug affects 61 people
Affects Status Importance Assigned to Milestone
network-manager (Ubuntu)
High
Unassigned
wpasupplicant (Ubuntu)
High
Unassigned

Bug Description

Hi,

I'm constantly having issues where my WiFi connection doesn't re-establish after resuming from suspend. I think it may be a race where the interface isn't ready yet and systemd-sleep calls /lib/systemd/system-sleep/wpasupplicant (which is a wrapper to wpa_cli).

I normally restart NetworkManager but then found that calling 'wpa_cli resume' works also.

Here's the logs:

| Mar 12 13:53:06 ragnar.local kernel: psmouse serio1: synaptics: quirked min/max coordinates: x [1024..5112], y [2024..4832]
| Mar 12 13:53:06 ragnar.local kernel: PM: resume of devices complete after 562.709 msecs
| Mar 12 13:53:06 ragnar.local kernel: PM: Finishing wakeup.
| Mar 12 13:53:06 ragnar.local systemd[1]: Time has been changed
| Mar 12 13:53:06 ragnar.local systemd[1066]: Time has been changed
| Mar 12 13:53:06 ragnar.local kernel: Restarting tasks ... done.
| Mar 12 13:53:06 ragnar.local systemd-sleep[29174]: System resumed.
| Mar 12 13:53:06 ragnar.local systemd-sleep[29174]: Failed to connect to non-global ctrl_ifname: (nil) error: No such file or directory
| Mar 12 13:53:06 ragnar.local systemd-sleep[29227]: /lib/systemd/system-sleep/wpasupplicant failed with error code 255.
| Mar 12 13:53:06 ragnar.local systemd[1]: Started Suspend.
| Mar 12 13:53:06 ragnar.local systemd[1]: sleep.target: Unit not needed anymore. Stopping.
| Mar 12 13:53:06 ragnar.local systemd[1]: Stopped target Sleep.
| Mar 12 13:53:06 ragnar.local systemd[1]: Reached target Suspend.
| Mar 12 13:53:06 ragnar.local systemd[1]: suspend.target: Unit is bound to inactive unit systemd-suspend.service. Stopping, too.
| Mar 12 13:53:06 ragnar.local NetworkManager[23292]: <info> wake requested (sleeping: yes enabled: yes)
| Mar 12 13:53:06 ragnar.local systemd[1]: Stopped target Suspend.
| Mar 12 13:53:06 ragnar.local NetworkManager[23292]: <info> waking up...
| Mar 12 13:53:06 ragnar.local systemd-logind[662]: Operation 'sleep' finished.
| Mar 12 13:53:06 ragnar.local kernel: IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
| Mar 12 13:53:06 ragnar.local kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
| Mar 12 13:53:06 ragnar.local NetworkManager[23292]: <info> (wlp3s0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
| Mar 12 13:53:06 ragnar.local kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
| Mar 12 13:53:07 ragnar.local kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
| Mar 12 13:53:07 ragnar.local kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
| Mar 12 13:53:07 ragnar.local NetworkManager[23292]: <info> NetworkManager state is now DISCONNECTED
| Mar 12 13:53:07 ragnar.local kernel: IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
| Mar 12 13:53:07 ragnar.local wpa_supplicant[23157]: dbus: wpa_dbus_get_object_properties: failed to get object properties: (none) none
| Mar 12 13:53:07 ragnar.local wpa_supplicant[23157]: dbus: Failed to construct signal
| Mar 12 13:53:07 ragnar.local wpa_supplicant[23157]: Could not read interface p2p-dev-wlp3s0 flags: No such device
| Mar 12 13:53:07 ragnar.local NetworkManager[23292]: <info> (wlp3s0): supplicant interface state: starting -> ready
| Mar 12 13:53:07 ragnar.local NetworkManager[23292]: <info> (wlp3s0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
| Mar 12 13:53:07 ragnar.local NetworkManager[23292]: <info> Device 'wlp3s0' has no connection; scheduling activate_check in 0 seconds.
| Mar 12 13:53:07 ragnar.local kernel: IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready

Thanks,

Haw
---
ApportVersion: 2.20-0ubuntu3
Architecture: amd64
CurrentDesktop: Unity
DistroRelease: Ubuntu 16.04
IfupdownConfig:
 # interfaces(5) file used by ifup(8) and ifdown(8)
 auto lo
 iface lo inet loopback
InstallationDate: Installed on 2014-04-24 (687 days ago)
InstallationMedia: Ubuntu 14.04 LTS "Trusty Tahr" - Release amd64 (20140417)
Package: wpasupplicant
PackageArchitecture: amd64
ProcVersionSignature: Ubuntu 4.4.0-11.26-generic 4.4.4
RfKill: Error: [Errno 2] No such file or directory
Tags: xenial
Uname: Linux 4.4.0-11-generic x86_64
UpgradeStatus: No upgrade log present (probably fresh install)
UserGroups: adm cdrom dialout dip lpadmin plugdev sudo users
_MarkForUpload: True
modified.conffile..etc.NetworkManager.NetworkManager.conf: [modified]
modified.conffile..etc.dnsmasq.d.network.manager: [modified]
mtime.conffile..etc.NetworkManager.NetworkManager.conf: 2015-09-12T15:03:20.815898
mtime.conffile..etc.dnsmasq.d.network.manager: 2014-07-29T22:12:51.096293
nmcli-con:
 NAME UUID TYPE TIMESTAMP TIMESTAMP-REAL AUTOCONNECT AUTOCONNECT-PRIORITY READONLY DBUS-PATH ACTIVE DEVICE STATE ACTIVE-PATH
 hld-2.4GHz deffb41a-c707-4088-a887-36d63f43a6a0 802-11-wireless 1457784347 Sat 12 Mar 2016 11:05:47 PM AEDT yes 0 no /org/freedesktop/NetworkManager/Settings/0 yes wlp3s0 activated /org/freedesktop/NetworkManager/ActiveConnection/12
nmcli-dev:
 DEVICE TYPE STATE DBUS-PATH CONNECTION CON-UUID CON-PATH
 wlp3s0 wifi connected /org/freedesktop/NetworkManager/Devices/0 hld-2.4GHz deffb41a-c707-4088-a887-36d63f43a6a0 /org/freedesktop/NetworkManager/ActiveConnection/12
 lo loopback unmanaged /org/freedesktop/NetworkManager/Devices/1 -- -- --
nmcli-nm: Error: command ['nmcli', '-f', 'all', 'nm'] failed with exit code 2: Error: Object 'nm' is unknown, try 'nmcli help'.

Haw Loeung (hloeung) wrote :

| [hloeung@ragnar tmp]$ apt-cache policy systemd wpasupplicant
| systemd:
| Installed: 229-2ubuntu1
| Candidate: 229-2ubuntu1
| Version table:
| *** 229-2ubuntu1 500
| 500 http://archive.ubuntu.com/ubuntu xenial/main amd64 Packages
| 100 /var/lib/dpkg/status
| wpasupplicant:
| Installed: 2.4-0ubuntu6
| Candidate: 2.4-0ubuntu6
| Version table:
| *** 2.4-0ubuntu6 500
| 500 http://archive.ubuntu.com/ubuntu xenial/main amd64 Packages
| 100 /var/lib/dpkg/status

tags: added: xenial
Martin Pitt (pitti) wrote :

Which Ubuntu release is that, wily or xenial? (Please use apport to file bugs).

/lib/systemd/system-sleep/wpasupplicant is a nasty hack/workaround introduced in bug 1422143; this is mirroring what we did before in/usr/lib/pm-utils/sleep.d/60_wpa_supplicant, but this really needs to be fixed properly in NM or wpa (not sure which) at some point..

no longer affects: systemd (Ubuntu)
Martin Pitt (pitti) wrote :

Mathieu, did you see this before? Any hints what to do here?

@Haw: Can you please include the full logs before and after suspend? The timestamps indicate that this was only for the suspend part. Thanks!

Haw Loeung (hloeung) wrote :
Download full text (18.8 KiB)

@Martin, it's Xenial.

| Mar 12 17:35:25 ragnar NetworkManager[23292]: <info> sleep requested (sleeping: no enabled: yes)
| Mar 12 17:35:25 ragnar NetworkManager[23292]: <info> sleeping...
| Mar 12 17:35:25 ragnar NetworkManager[23292]: <info> (wlp3s0): device state change: activated -> unmanaged (reason 'sleeping') [100 10 37]
| Mar 12 17:35:26 ragnar NetworkManager[23292]: <info> (wlp3s0): canceled DHCP transaction, DHCP client pid 8279
| Mar 12 17:35:26 ragnar NetworkManager[23292]: <info> (wlp3s0): DHCPv4 state changed bound -> done
| Mar 12 17:35:26 ragnar kernel: [143996.969825] wlp3s0: deauthenticating from 24:a4:3c:99:31:37 by local choice (Reason: 3=DEAUTH_LEAVING)
| Mar 12 17:35:26 ragnar wpa_supplicant[23157]: wlp3s0: CTRL-EVENT-DISCONNECTED bssid=24:a4:3c:99:31:37 reason=3 locally_generated=1
| Mar 12 17:35:26 ragnar NetworkManager[23292]: <info> NetworkManager state is now ASLEEP
| Mar 12 17:35:26 ragnar wpa_supplicant[23157]: p2p-dev-wlp3s0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
| Mar 12 17:35:26 ragnar kernel: [143996.986106] cfg80211: World regulatory domain updated:
| Mar 12 17:35:26 ragnar kernel: [143996.986111] cfg80211: DFS Master region: unset
| Mar 12 17:35:26 ragnar kernel: [143996.986113] cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
| Mar 12 17:35:26 ragnar kernel: [143996.986117] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
| Mar 12 17:35:26 ragnar kernel: [143996.986120] cfg80211: (2457000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
| Mar 12 17:35:26 ragnar kernel: [143996.986122] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A)
| Mar 12 17:35:26 ragnar kernel: [143996.986125] cfg80211: (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (N/A)
| Mar 12 17:35:26 ragnar kernel: [143996.986129] cfg80211: (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (0 s)
| Mar 12 17:35:26 ragnar kernel: [143996.986133] cfg80211: (5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2000 mBm), (0 s)
| Mar 12 17:35:26 ragnar kernel: [143996.986136] cfg80211: (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
| Mar 12 17:35:26 ragnar kernel: [143996.986139] cfg80211: (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)
| Mar 12 17:35:26 ragnar wpa_supplicant[23157]: p2p-dev-wlp3s0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=AU
| Mar 12 17:35:26 ragnar kernel: [143996.990173] cfg80211: Regulatory domain changed to country: AU
| Mar 12 17:35:26 ragnar kernel: [143996.990177] cfg80211: DFS Master region: ETSI
| Mar 12 17:35:26 ragnar kernel: [143996.990179] cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
| Mar 12 17:35:26 ragnar kernel: [143996.990183] cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
| Mar 12 17:35:26 ragnar kernel: [143996.990186] cfg80211: (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 1700 mBm), (N/A)
| Mar 12 17:35:26 ragnar kernel: [143996.990189] cfg80211: (5250000 KHz - 5330000 KHz @ 80000 KHz, 1600...

tags: added: apport-collected
description: updated
Haw Loeung (hloeung) wrote : CRDA.txt

apport information

apport information

apport information

Launchpad Janitor (janitor) wrote :

Status changed to 'Confirmed' because the bug affects multiple users.

Changed in network-manager (Ubuntu):
status: New → Confirmed
Changed in wpasupplicant (Ubuntu):
status: New → Confirmed
Changed in wpasupplicant (Ubuntu):
importance: Undecided → High
Changed in network-manager (Ubuntu):
importance: Undecided → High
Christian Reis (kiko) on 2016-04-19
tags: added: regression-release
Christian Reis (kiko) wrote :

I've run into this with my x220 which was recently upgraded to Xenial as well. It is not consistent; it happens at maybe 1 out of 3 suspend/resume cycles.

Removing and reinserting the iwldvm module also fixes the issue, but kudos to Haw for noting that it doesn't seem to be a lower-level bug but rather in NM itself; as he suggests, a `sudo wpa_cli resume` triggers a reconnection.

Toggling the kill switch does not cause a reconnection to happen, nor does disabling and reenabling wifi.

The UI symptom is that the list of available networks in the dropdown does not update; either a single item or no item is displayed, and no reconnection happens (regardless of whether or not the item displayed is one which you have associated with before).

Mark Stosberg (markstos) wrote :

I have this problem on a Dell XPS 2013 (Haswell) running Ubuntu 16.04. However, trying to workaround it like results in an error:

    sudo wpa_cli resume

Failed to connect to non-global ctrl_ifname: (nil) error: No such file or directory.

This bug is the same as, or similar to:

No wifi connection after suspend with systemd due to missing "wpa_cli suspend"
https://bugs.launchpad.net/hundredpapercuts/+bug/1422143

Chaos Onion (chaosonion) wrote :

I'm having this problem on Lenovo G410 with the latest release 16.04 fully updated as of July 22, 2016. After coming back from suspend, the wireless icon disappears and is replaced by the ethernet connection icon. Although the wifi stays connected to it's last remembered connection, the list of wireless networks also disappears from network-manager.

Stew Mat (monolit) wrote :

I'm having this with my Lenovo Thinkpad T420. It happens around 1 time out of 3. Sometimes the connected wifi icon is replaced by the ethernet one, sometimes by the unconnected wifi icon.

"wpa_cli resume" fixes it.

Thanks @Haw for the workaround.

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers