[pkg-wpa-devel] Bug#835648: Bug#835648: wpasupplicant: suspend takes very long due to problematic system-sleep hook
Andrew Shadura
andrew at shadura.me
Tue Aug 30 20:36:48 UTC 2016
On 28/08/16 00:39, Tomas Janousek wrote:
> Package: wpasupplicant
> Version: 2.5-2+v2.4-2
> Severity: normal
Martin, could you please have a look?
> I recently upgraded the wpasupplicant package and my system started taking a
> LONG time to suspend. My journal contains:
>
> Aug 27 23:40:53 notes NetworkManager[1904]: <info> [1472334053.2710] manager: sleep requested (sleeping: no enabled: yes)
> Aug 27 23:40:53 notes NetworkManager[1904]: <info> [1472334053.2710] manager: sleeping...
> Aug 27 23:40:53 notes NetworkManager[1904]: <info> [1472334053.2711] device (eth0): state change: unavailable -> unmanaged (reason 'sleeping') [20 10 37]
> Aug 27 23:40:53 notes kernel: e1000e: eth0 NIC Link is Down
> Aug 27 23:40:53 notes NetworkManager[1904]: <info> [1472334053.3941] manager: NetworkManager state is now ASLEEP
> Aug 27 23:40:53 notes NetworkManager[1904]: <info> [1472334053.3974] device (wlan1): state change: activated -> deactivating (reason 'sleeping') [100 110 37]
> Aug 27 23:40:53 notes NetworkManager[1904]: <info> [1472334053.4048] device (wlan1): state change: deactivating -> disconnected (reason 'sleeping') [110 30 37]
> Aug 27 23:40:53 notes NetworkManager[1904]: <info> [1472334053.4232] dhcp4 (wlan1): canceled DHCP transaction, DHCP client pid 18447
> Aug 27 23:40:53 notes NetworkManager[1904]: <info> [1472334053.4233] dhcp4 (wlan1): state changed bound -> done
> Aug 27 23:40:53 notes kernel: wlan1: deauthenticating from c4:27:95:77:a6:b8 by local choice (Reason: 3=DEAUTH_LEAVING)
> Aug 27 23:40:53 notes wpa_supplicant[2812]: wlan1: CTRL-EVENT-DISCONNECTED bssid=c4:27:95:77:a6:b8 reason=3 locally_generated=1
> Aug 27 23:40:53 notes NetworkManager[1904]: <info> [1472334053.4548] dns-mgr: Writing DNS information to /sbin/resolvconf
> Aug 27 23:40:53 notes wpa_supplicant[2812]: wlan1: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
> Aug 27 23:40:53 notes NetworkManager[1904]: <warn> [1472334053.5079] sup-iface[0x9947a98,wlan1]: connection disconnected (reason -3)
> Aug 27 23:40:53 notes NetworkManager[1904]: <info> [1472334053.5080] device (wlan1): supplicant interface state: completed -> disconnected
> Aug 27 23:40:53 notes NetworkManager[1904]: <info> [1472334053.5091] device (wlan1): state change: disconnected -> unmanaged (reason 'sleeping') [30 10 37]
> Aug 27 23:40:53 notes systemd[1]: Reached target Sleep.
> Aug 27 23:40:53 notes systemd[1]: Starting Suspend...
> Aug 27 23:40:54 notes wpa_supplicant[2812]: nl80211: deinit ifname=wlan1 disabled_11b_rates=0
> Aug 27 23:41:04 notes systemd-sleep[18924]: Selected interface 'wlan1'
> Aug 27 23:41:04 notes systemd-sleep[18924]: 'SUSPEND' command timed out.
> Aug 27 23:41:04 notes systemd-sleep[18928]: /lib/systemd/system-sleep/wpasupplicant failed with error code 254.
> Aug 27 23:41:04 notes systemd-sleep[18924]: Suspending system...
>
> Disabling the /lib/systemd/system-sleep/wpasupplicant script fixes the problem
> for me. From what NetworkManagers prints to the journal it seems to me that
> the /lib/systemd/system-sleep/wpasupplicant script is unnecessary, and since
> it makes suspend take 10 seconds longer, it is actually not just unnecessary,
> but harmful.
>
> I suspend the system by invoking "systemctl suspend" via acpid.
>
> I tried to research this a bit. If I manually invoke
>
> dbus-send --print-reply --system --dest=org.freedesktop.NetworkManager /org/freedesktop/NetworkManager org.freedesktop.NetworkManager.Sleep boolean:true
>
> and then try to "/sbin/wpa_cli suspend", I always get:
>
> Failed to connect to non-global ctrl_ifname: (nil) error: No such file or directory
>
> Seems to me then that the 10s delay I'm getting is a race condition between NM
> sleeping and wpa_cli attempting to suspend. It's also interesting that on my
> hardware (ThinkPad T420, Intel(R) Centrino(R) Advanced-N 6205 AGN, REV=0xB0)
> wpa_cli suspend does nothing at all -- after invoking it and getting OK, wifi
> stays connected and pings.
>
> I also looked into dbus-monitor output and in my case NM drops the inhibitor
> only after putting both eth and wlan devices offline, unlike in the launchpad
> issue that the /lib/systemd/system-sleep/wpasupplicant is trying to fix.
>
> -- System Information:
> Debian Release: stretch/sid
> APT prefers testing
> APT policy: (980, 'testing'), (980, 'stable'), (500, 'unstable-debug'), (500, 'testing-debug'), (500, 'unstable'), (500, 'stable'), (200, 'experimental'), (1, 'experimental-debug')
> Architecture: i386 (x86_64)
> Foreign Architectures: amd64
>
> Kernel: Linux 4.4.19-lis64+ (SMP w/4 CPU cores; PREEMPT)
> Locale: LANG=cs_CZ.UTF-8, LC_CTYPE=cs_CZ.UTF-8 (charmap=UTF-8)
> Shell: /bin/sh linked to /bin/bash
> Init: systemd (via /run/systemd/system)
>
> Versions of packages wpasupplicant depends on:
> ii adduser 3.115
> ii libc6 2.23-4
> ii libdbus-1-3 1.10.10-1
> ii libnl-3-200 3.2.27-1
> ii libnl-genl-3-200 3.2.27-1
> ii libpcsclite1 1.8.18-1
> ii libreadline6 6.3-8+b4
> ii libssl1.0.2 1.0.2h-1
> ii lsb-base 9.20160629
>
> wpasupplicant recommends no packages.
>
> Versions of packages wpasupplicant suggests:
> pn libengine-pkcs11-openssl <none>
> ii wpagui 2.5-2+v2.4-2
>
> -- no debconf information
>
> -- debsums errors found:
> debsums: changed file /lib/systemd/system-sleep/wpasupplicant (from wpasupplicant package)
>
--
Cheers,
Andrew
More information about the Pkg-wpa-devel
mailing list