search

jakeday / linux-surface

Linux Kernel for Surface Devices
2.59k stars 242 forks source link

[Surface Pro 3] unexpected hibernation/sleep #578

Closed RussH closed 5 years ago

RussH commented 5 years ago

I have only seen this on the 5.x kernels, but the SP3 seems to enter sleep unexpectedly. Dmesg isn't incredibly useful, nor journalctl. Is there anyplace I can see what triggered the sleep?

all I can tell from dmesg is that (in this instance) the CPU wasn't throttled at the time, so it likely wasn't a thermal shutdown.

journalctl grepping on 'sleep' - the first 'invocation seems to be from NetworkManager? `Sep 27 11:08:16 russh-Surface-Pro-3 systemd-logind[721]: Operation 'sleep' finished.

Sep 27 13:39:46 russh-Surface-Pro-3 NetworkManager[31421]: [1569587986.4273] manager: sleep: sleep requested (sleeping: no enabled: yes)

Sep 27 13:39:46 russh-Surface-Pro-3 NetworkManager[31421]: [1569587986.4318] device (mlan0): state change: activated -> deactivating (reason 'sleeping', sys-iface-state: 'managed') Sep 27 13:39:46 russh-Surface-Pro-3 NetworkManager[31421]: [1569587986.4586] device (mlan0): state change: deactivating -> disconnected (reason 'sleeping', sys-iface-state: 'managed') Sep 27 13:39:46 russh-Surface-Pro-3 NetworkManager[31421]: [1569587986.5293] device (mlan0): state change: disconnected -> unmanaged (reason 'sleeping', sys-iface-state: 'managed') Sep 27 13:39:47 russh-Surface-Pro-3 systemd-sleep[13138]: Suspending system... Sep 27 13:47:51 russh-Surface-Pro-3 kernel: ACPI: Preparing to enter system sleep state S4 Sep 27 13:47:51 russh-Surface-Pro-3 kernel: ACPI: Waking up from system sleep state S4`

If there's anyplace else I can look, please let me know

tmarkov commented 5 years ago

In journalctl if you find the line with Reached target Sleep, a few lines above I see Sep 27 01:04:43 surface systemd-logind[576]: Power key pressed.

RussH commented 5 years ago

yep - all I see here is Network Manager starting it off at Sep 27 13:39:46

Sep 27 13:39:01 russh-Surface-Pro-3 CRON[12768]: pam_unix(cron:session): session opened for user root by (uid=0) Sep 27 13:39:01 russh-Surface-Pro-3 CRON[12769]: (root) CMD ( [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib/php/sessionclean; fi) Sep 27 13:39:01 russh-Surface-Pro-3 CRON[12768]: pam_unix(cron:session): session closed for user root Sep 27 13:39:02 russh-Surface-Pro-3 systemd[1]: Starting Clean php session files... Sep 27 13:39:03 russh-Surface-Pro-3 systemd[1]: Started Clean php session files. Sep 27 13:39:46 russh-Surface-Pro-3 NetworkManager[31421]: [1569587986.4273] manager: sleep: sleep requested (sleeping: no enabled: yes) Sep 27 13:39:46 russh-Surface-Pro-3 NetworkManager[31421]: <info> [1569587986.4288] manager: NetworkManager state is now ASLEEP Sep 27 13:39:46 russh-Surface-Pro-3 NetworkManager[31421]: <info> [1569587986.4318] device (mlan0): state change: activated -> deactivating (reason 'sleeping', sys-iface-state: 'managed') Sep 27 13:39:46 russh-Surface-Pro-3 NetworkManager[31421]: <info> [1569587986.4586] device (mlan0): state change: deactivating -> disconnected (reason 'sleeping', sys-iface-state: 'managed') Sep 27 13:39:46 russh-Surface-Pro-3 dbus-daemon[746]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.318' (uid=0 pid=31421 comm="/usr/sbin/NetworkManager --no-daemon " label="kernel") Sep 27 13:39:46 russh-Surface-Pro-3 avahi-daemon[739]: Withdrawing address record for 2a00:23c7:a304:d301:7d5a:3888:25b7:2fc4 on mlan0. Sep 27 13:39:46 russh-Surface-Pro-3 avahi-daemon[739]: Withdrawing address record for 2a00:23c7:a304:d301:b636:d272:9c86:5670 on mlan0. Sep 27 13:39:46 russh-Surface-Pro-3 avahi-daemon[739]: Leaving mDNS multicast group on interface mlan0.IPv6 with address 2a00:23c7:a304:d301:b636:d272:9c86:5670. Sep 27 13:39:46 russh-Surface-Pro-3 avahi-daemon[739]: Joining mDNS multicast group on interface mlan0.IPv6 with address fe80::d0c7:7c7e:6fc0:e155. Sep 27 13:39:46 russh-Surface-Pro-3 NetworkManager[31421]: <info> [1569587986.4970] dhcp4 (mlan0): canceled DHCP transaction, DHCP client pid 31528 Sep 27 13:39:46 russh-Surface-Pro-3 avahi-daemon[739]: Registering new address record for fe80::d0c7:7c7e:6fc0:e155 on mlan0.*. Sep 27 13:39:46 russh-Surface-Pro-3 whoopsie[983]: [13:39:46] offline Sep 27 13:39:46 russh-Surface-Pro-3 NetworkManager[31421]: <info> [1569587986.4970] dhcp4 (mlan0): state changed bound -> done Sep 27 13:39:46 russh-Surface-Pro-3 kernel: mwifiex_pcie 0000:01:00.0: info: successfully disconnected from 78:dd:12:c5:50:84: reason code 3 Sep 27 13:39:46 russh-Surface-Pro-3 avahi-daemon[739]: Withdrawing address record for fe80::d0c7:7c7e:6fc0:e155 on mlan0. Sep 27 13:39:46 russh-Surface-Pro-3 NetworkManager[31421]: <info> [1569587986.5003] dhcp6 (mlan0): canceled DHCP transaction Sep 27 13:39:46 russh-Surface-Pro-3 avahi-daemon[739]: Leaving mDNS multicast group on interface mlan0.IPv6 with address fe80::d0c7:7c7e:6fc0:e155. Sep 27 13:39:46 russh-Surface-Pro-3 systemd[1]: Starting Network Manager Script Dispatcher Service... Sep 27 13:39:46 russh-Surface-Pro-3 avahi-daemon[739]: Interface mlan0.IPv6 no longer relevant for mDNS. Sep 27 13:39:46 russh-Surface-Pro-3 NetworkManager[31421]: <info> [1569587986.5293] device (mlan0): state change: disconnected -> unmanaged (reason 'sleeping', sys-iface-state: 'managed') Sep 27 13:39:46 russh-Surface-Pro-3 avahi-daemon[739]: Withdrawing address record for 192.168.1.196 on mlan0. Sep 27 13:39:46 russh-Surface-Pro-3 avahi-daemon[739]: Leaving mDNS multicast group on interface mlan0.IPv4 with address 192.168.1.196. Sep 27 13:39:46 russh-Surface-Pro-3 avahi-daemon[739]: Interface mlan0.IPv4 no longer relevant for mDNS. Sep 27 13:39:46 russh-Surface-Pro-3 wpa_supplicant[818]: mlan0: CTRL-EVENT-DISCONNECTED bssid=78:dd:12:c5:50:84 reason=3 locally_generated=1 Sep 27 13:39:46 russh-Surface-Pro-3 dbus-daemon[746]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Sep 27 13:39:46 russh-Surface-Pro-3 systemd[1]: Started Network Manager Script Dispatcher Service. Sep 27 13:39:46 russh-Surface-Pro-3 nm-dispatcher[13087]: req:1 'connectivity-change': new request (1 scripts) Sep 27 13:39:46 russh-Surface-Pro-3 nm-dispatcher[13087]: req:1 'connectivity-change': start running ordered scripts... Sep 27 13:39:46 russh-Surface-Pro-3 nm-dispatcher[13087]: req:2 'down' [mlan0]: new request (1 scripts) Sep 27 13:39:46 russh-Surface-Pro-3 nm-dispatcher[13087]: req:2 'down' [mlan0]: start running ordered scripts... Sep 27 13:39:46 russh-Surface-Pro-3 whoopsie[983]: [13:39:46] Cannot reach: https://daisy.ubuntu.com Sep 27 13:39:47 russh-Surface-Pro-3 systemd[1]: Reached target Sleep.

RussH commented 5 years ago

Ahh, may have found the issue - unrelated to jakeday, let me test