You are not logged in.
Hello-
Trying to make suspend more useful on my MS surface pro 3.
currently it seems like it wakes from suspend seemingly randomly.
It doesn't seem to matter if suspend was evoked via power button or via typecover shut.
I found https://bbs.archlinux.org/viewtopic.php?id=183410, which is similar, but it is marked as 'solved'- and i'd like to get to the cause of this and get it fixed upstream, if there are folks that can help troubleshoot it.
Side note; logs for PM stuff seem odd- both this device and another laptop that appears to sleep/wake just fine. Both have information that appears to be logged after the logging service stops writing to disk, which shows up in logs after the wake- but the type of log items appear to be sleep, i.e. 'Entering freeze sleep'
Here is journalctl output from a wake-up in the middle of the night after using the power button to suspend
Dec 06 21:18:48 surfacearch systemd-logind[305]: Power key pressed.
Dec 06 21:18:48 surfacearch NetworkManager[294]: <info> sleep requested (sleeping: no enabled: yes)
Dec 06 21:18:48 surfacearch NetworkManager[294]: <info> sleeping...
Dec 06 21:18:48 surfacearch NetworkManager[294]: <info> (wlp1s0): device state change: activated -> unmanaged (reason 'sleeping') [100 10 37]
Dec 06 21:18:48 surfacearch NetworkManager[294]: <info> (wlp1s0): canceled DHCP transaction, DHCP client pid 752
Dec 06 21:18:48 surfacearch NetworkManager[294]: <info> (wlp1s0): DHCPv4 state changed bound -> done
Dec 06 21:18:48 surfacearch NetworkManager[294]: <info> (wlp1s0): canceled DHCP transaction, DHCP client pid 983
Dec 06 21:18:48 surfacearch NetworkManager[294]: <info> (wlp1s0): DHCPv6 state changed bound -> done
Dec 06 21:18:48 surfacearch avahi-daemon[304]: Withdrawing address record for 192.168.11.138 on wlp1s0.
Dec 06 21:18:48 surfacearch avahi-daemon[304]: Leaving mDNS multicast group on interface wlp1s0.IPv4 with address 192.168.11.138.
Dec 06 21:18:48 surfacearch avahi-daemon[304]: Interface wlp1s0.IPv4 no longer relevant for mDNS.
Dec 06 21:18:48 surfacearch avahi-daemon[304]: Withdrawing address record for fde0:6f97:58ce:0:c233:5eff:fe2a:8607 on wlp1s0.
Dec 06 21:18:48 surfacearch kernel: cfg80211: Exceeded CRDA call max attempts. Not calling CRDA
Dec 06 21:18:48 surfacearch avahi-daemon[304]: Leaving mDNS multicast group on interface wlp1s0.IPv6 with address fde0:6f97:58ce:0:c233:5eff:fe2a:8607.
Dec 06 21:18:48 surfacearch avahi-daemon[304]: Joining mDNS multicast group on interface wlp1s0.IPv6 with address fde0:6f97:58ce::44e.
Dec 06 21:18:48 surfacearch avahi-daemon[304]: Withdrawing address record for fde0:6f97:58ce::44e on wlp1s0.
Dec 06 21:18:48 surfacearch avahi-daemon[304]: Leaving mDNS multicast group on interface wlp1s0.IPv6 with address fde0:6f97:58ce::44e.
Dec 06 21:18:48 surfacearch avahi-daemon[304]: Interface wlp1s0.IPv6 no longer relevant for mDNS.
Dec 06 21:18:48 surfacearch NetworkManager[294]: <info> Writing DNS information to /usr/bin/resolvconf
Dec 06 21:18:48 surfacearch NetworkManager[294]: <info> Removing DNS information from /usr/bin/resolvconf
Dec 06 21:18:48 surfacearch NetworkManager[294]: <info> NetworkManager state is now ASLEEP
Dec 06 21:18:48 surfacearch NetworkManager[294]: <info> (90:68:C3:F8:E0:B9): device state change: disconnected -> unmanaged (reason 'sleeping') [30 10 37]
Dec 06 21:18:48 surfacearch dbus[296]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Dec 06 21:18:48 surfacearch NetworkManager[294]: <warn> Failed to GDBus.Error:fi.w1.wpa_supplicant1.NotConnected: This interface is not connected: disconnect.
Dec 06 21:18:48 surfacearch systemd[1]: Reached target Sleep.
Dec 06 21:18:48 surfacearch systemd[1]: Starting Suspend...
Dec 06 21:18:48 surfacearch systemd[1]: Starting Network Manager Script Dispatcher Service...
Dec 06 21:18:48 surfacearch systemd-sleep[1181]: Suspending system...
Dec 06 21:18:48 surfacearch dbus[296]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Dec 07 04:01:21 surfacearch kernel: PM: Syncing filesystems ... done.
Dec 07 04:01:21 surfacearch kernel: PM: Preparing system for freeze sleep
Dec 07 04:01:21 surfacearch kernel: Freezing user space processes ... (elapsed 0.001 seconds) done.
Dec 07 04:01:21 surfacearch kernel: Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
Dec 07 04:01:21 surfacearch kernel: PM: Entering freeze sleep
Dec 07 04:01:21 surfacearch kernel: Suspending console(s) (use no_console_suspend to debug)
Dec 07 04:01:21 surfacearch kernel: mwifiex_pcie 0000:01:00.0: None of the WOWLAN triggers enabled
Dec 07 04:01:21 surfacearch kernel: sd 0:0:0:0: [sda] Synchronizing SCSI cache
Dec 07 04:01:21 surfacearch kernel: sd 0:0:0:0: [sda] Stopping disk
Dec 07 04:01:21 surfacearch kernel: PM: suspend of devices complete after 252.412 msecs
Dec 07 04:01:21 surfacearch kernel: PM: late suspend of devices complete after 31.689 msecs
Dec 07 04:01:21 surfacearch kernel: xhci_hcd 0000:00:14.0: System wakeup enabled by ACPI
Dec 07 04:01:21 surfacearch kernel: PM: noirq suspend of devices complete after 14.315 msecs
Dec 07 04:01:21 surfacearch kernel: PM: suspend-to-idle
Dec 07 04:01:21 surfacearch kernel: PM: resume from suspend-to-idle
Dec 07 04:01:21 surfacearch kernel: xhci_hcd 0000:00:14.0: System wakeup disabled by ACPI
Dec 07 04:01:21 surfacearch kernel: PM: noirq resume of devices complete after 105.639 msecs
Dec 07 04:01:21 surfacearch kernel: PM: early resume of devices complete after 53.161 msecs
Dec 07 04:01:21 surfacearch kernel: sd 0:0:0:0: [sda] Starting disk
Dec 07 04:01:21 surfacearch kernel: rtc_cmos 00:01: System wakeup disabled by ACPI
Dec 07 04:01:21 surfacearch kernel: ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
Dec 07 04:01:21 surfacearch kernel: ata1.00: configured for UDMA/133
Dec 07 04:01:21 surfacearch kernel: PM: resume of devices complete after 860.942 msecs
Dec 07 04:01:21 surfacearch kernel: PM: Finishing wakeup.
Dec 07 04:01:21 surfacearch kernel: Restarting tasks ... done.
Dec 07 04:01:21 surfacearch systemd[727]: Time has been changed
Dec 07 04:01:21 surfacearch systemd[1]: Started Network Manager Script Dispatcher Service.
Dec 07 04:01:21 surfacearch systemd[1]: Time has been changed
Dec 07 04:01:21 surfacearch systemd[1]: Starting Rotate log files...
Dec 07 04:01:21 surfacearch systemd[1]: Starting Verify integrity of password and group files...
Dec 07 04:01:21 surfacearch systemd[1]: Starting Update man-db cache...
Dec 07 04:01:21 surfacearch systemd[1]: Started Verify integrity of password and group files.
Dec 07 04:01:21 surfacearch systemd-sleep[1181]: System resumed.
Dec 07 04:01:21 surfacearch systemd[1]: Started Suspend.
Dec 07 04:01:21 surfacearch systemd[1]: sleep.target: Unit not needed anymore. Stopping.
Dec 07 04:01:21 surfacearch systemd[1]: Stopped target Sleep.
Dec 07 04:01:21 surfacearch systemd[1]: Reached target Suspend.
Dec 07 04:01:21 surfacearch systemd[1]: suspend.target: Unit is bound to inactive unit systemd-suspend.service. Stopping, too.
Dec 07 04:01:21 surfacearch systemd[1]: Stopped target Suspend.
Dec 07 04:01:21 surfacearch systemd-logind[305]: Operation 'sleep' finished.
Dec 07 04:01:21 surfacearch NetworkManager[294]: <info> wake requested (sleeping: yes enabled: yes)
Dec 07 04:01:21 surfacearch NetworkManager[294]: <info> waking up...
Dec 07 04:01:21 surfacearch NetworkManager[294]: <info> (wlp1s0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Dec 07 04:01:21 surfacearch NetworkManager[294]: <info> (90:68:C3:F8:E0:B9): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Dec 07 04:01:21 surfacearch NetworkManager[294]: <info> NetworkManager state is now DISCONNECTED
Dec 07 04:01:21 surfacearch kernel: IPv6: ADDRCONF(NETDEV_UP): wlp1s0: link is not ready
Dec 07 04:01:21 surfacearch kernel: IPv6: ADDRCONF(NETDEV_UP): wlp1s0: link is not ready
Dec 07 04:01:21 surfacearch NetworkManager[294]: <info> (90:68:C3:F8:E0:B9): device state change: unavailable -> disconnected (reason 'none') [20 30 0]
Dec 07 04:01:21 surfacearch systemd[1]: Started Rotate log files.
Dec 07 04:01:21 surfacearch NetworkManager[294]: <info> (wlp1s0) supports 5 scan SSIDs
Dec 07 04:01:21 surfacearch kernel: IPv6: ADDRCONF(NETDEV_UP): wlp1s0: link is not ready
Dec 07 04:01:21 surfacearch NetworkManager[294]: <info> (wlp1s0): supplicant interface state: starting -> ready
Dec 07 04:01:21 surfacearch NetworkManager[294]: <info> (wlp1s0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> (wlp1s0): supplicant interface state: ready -> inactive
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> Auto-activating connection 'HACKEDBOXII-A'.
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> (wlp1s0): Activation: starting connection 'HACKEDBOXII-A' (3acb76a4-3643-4bae-a191-1dde1ca92438)
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> (wlp1s0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> NetworkManager state is now CONNECTING
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> (wlp1s0): device state change: prepare -> config (reason 'none') [40 50 0]
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> (wlp1s0): Activation: (wifi) access point 'HACKEDBOXII-A' has security, but secrets are required.
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> (wlp1s0): device state change: config -> need-auth (reason 'none') [50 60 0]
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> (wlp1s0): device state change: need-auth -> prepare (reason 'none') [60 40 0]
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> (wlp1s0): device state change: prepare -> config (reason 'none') [40 50 0]
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> (wlp1s0): Activation: (wifi) connection 'HACKEDBOXII-A' has security, and secrets exist. No new secrets needed.
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> Config: added 'ssid' value 'HACKEDBOXII-A'
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> Config: added 'scan_ssid' value '1'
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> Config: added 'psk' value '<omitted>'
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> Config: set interface ap_scan to 1
Dec 07 04:01:24 surfacearch NetworkManager[294]: <info> (wlp1s0): supplicant interface state: inactive -> associating
Dec 07 04:01:24 surfacearch kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlp1s0: link becomes ready
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> (wlp1s0): supplicant interface state: associating -> completed
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> (wlp1s0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'HACKEDBOXII-A'.
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> (wlp1s0): device state change: config -> ip-config (reason 'none') [50 70 0]
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> Activation (wlp1s0) Beginning DHCPv4 transaction (timeout in 45 seconds)
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> dhclient started with pid 5140
Dec 07 04:01:25 surfacearch dhclient[5140]: DHCPREQUEST on wlp1s0 to 255.255.255.255 port 67
Dec 07 04:01:25 surfacearch dhclient[5140]: DHCPACK from 192.168.11.254
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> address 192.168.11.138
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> plen 24 (255.255.255.0)
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> gateway 192.168.11.254
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> server identifier 192.168.11.254
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> lease time 43200
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> nameserver '192.168.11.254'
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> domain name 'dryhollow'
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> (wlp1s0): DHCPv4 state changed unknown -> bound
Dec 07 04:01:25 surfacearch avahi-daemon[304]: Joining mDNS multicast group on interface wlp1s0.IPv4 with address 192.168.11.138.
Dec 07 04:01:25 surfacearch avahi-daemon[304]: New relevant interface wlp1s0.IPv4 for mDNS.
Dec 07 04:01:25 surfacearch avahi-daemon[304]: Registering new address record for 192.168.11.138 on wlp1s0.IPv4.
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> (wlp1s0): device state change: ip-config -> ip-check (reason 'none') [70 80 0]
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> (wlp1s0): device state change: ip-check -> secondaries (reason 'none') [80 90 0]
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> (wlp1s0): device state change: secondaries -> activated (reason 'none') [90 100 0]
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> NetworkManager state is now CONNECTED_LOCAL
Dec 07 04:01:25 surfacearch dhclient[5140]: bound to 192.168.11.138 -- renewal in 20002 seconds.
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> NetworkManager state is now CONNECTED_GLOBAL
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> Policy set 'HACKEDBOXII-A' (wlp1s0) as default for IPv4 routing and DNS.
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> Writing DNS information to /usr/bin/resolvconf
Dec 07 04:01:25 surfacearch NetworkManager[294]: <info> (wlp1s0): Activation: successful, device activated.
Dec 07 04:01:26 surfacearch avahi-daemon[304]: Joining mDNS multicast group on interface wlp1s0.IPv6 with address fe80::c233:5eff:fe2a:8607.
Dec 07 04:01:26 surfacearch avahi-daemon[304]: New relevant interface wlp1s0.IPv6 for mDNS.
Dec 07 04:01:26 surfacearch avahi-daemon[304]: Registering new address record for fe80::c233:5eff:fe2a:8607 on wlp1s0.*.
Dec 07 04:01:26 surfacearch NetworkManager[294]: <info> Activation (wlp1s0) Beginning DHCPv6 transaction (timeout in 45 seconds)
Dec 07 04:01:26 surfacearch NetworkManager[294]: <info> dhclient started with pid 7315
Dec 07 04:01:26 surfacearch NetworkManager[294]: <info> Writing DNS information to /usr/bin/resolvconf
Dec 07 04:01:27 surfacearch dhclient[7315]: XMT: Confirm on wlp1s0, interval 960ms.
Dec 07 04:01:27 surfacearch dhclient[7315]: RCV: Reply message on wlp1s0 from fe80::4ee6:76ff:fec4:71a0.
Dec 07 04:01:27 surfacearch dhclient[7315]: message status code NotOnLink.
Dec 07 04:01:27 surfacearch dhclient[7315]: RCV: Reply message on wlp1s0 from fe80::ea94:f6ff:fe91:3cf8.
Dec 07 04:01:27 surfacearch dhclient[7315]: Packet received, but nothing done with it.
Dec 07 04:01:27 surfacearch dhclient[7315]: XMT: Solicit on wlp1s0, interval 1040ms.
Dec 07 04:01:27 surfacearch dhclient[7315]: RCV: Advertise message on wlp1s0 from fe80::4ee6:76ff:fec4:71a0.
Dec 07 04:01:27 surfacearch dhclient[7315]: IA_NA status code NoAddrsAvail.
Dec 07 04:01:27 surfacearch dhclient[7315]: RCV: Advertise message on wlp1s0 from fe80::ea94:f6ff:fe91:3cf8.
Dec 07 04:01:28 surfacearch dhclient[7315]: XMT: Request on wlp1s0, interval 1070ms.
Dec 07 04:01:28 surfacearch dhclient[7315]: RCV: Reply message on wlp1s0 from fe80::ea94:f6ff:fe91:3cf8.
Dec 07 04:01:28 surfacearch NetworkManager[294]: <info> valid_lft -1
Dec 07 04:01:28 surfacearch NetworkManager[294]: <info> preferred_lft -1
Dec 07 04:01:28 surfacearch NetworkManager[294]: <info> address fde0:6f97:58ce::44e
Dec 07 04:01:28 surfacearch NetworkManager[294]: <info> nameserver 'fde0:6f97:58ce::1'
Dec 07 04:01:28 surfacearch NetworkManager[294]: <info> domain search 'dryhollow.'
Dec 07 04:01:28 surfacearch NetworkManager[294]: <info> (wlp1s0): DHCPv6 state changed unknown -> bound, event ID="5e:2a:86:07|1449489688"
Dec 07 04:01:28 surfacearch NetworkManager[294]: <info> Writing DNS information to /usr/bin/resolvconf
Dec 07 04:01:28 surfacearch avahi-daemon[304]: Leaving mDNS multicast group on interface wlp1s0.IPv6 with address fe80::c233:5eff:fe2a:8607.
Dec 07 04:01:28 surfacearch avahi-daemon[304]: Joining mDNS multicast group on interface wlp1s0.IPv6 with address fde0:6f97:58ce:0:c233:5eff:fe2a:8607.
Dec 07 04:01:28 surfacearch avahi-daemon[304]: Registering new address record for fde0:6f97:58ce:0:c233:5eff:fe2a:8607 on wlp1s0.*.
Dec 07 04:01:28 surfacearch avahi-daemon[304]: Withdrawing address record for fe80::c233:5eff:fe2a:8607 on wlp1s0.
Dec 07 04:01:29 surfacearch systemd[1]: Started Update man-db cache.
Dec 07 04:01:29 surfacearch avahi-daemon[304]: Registering new address record for fde0:6f97:58ce::44e on wlp1s0.*.
Dec 07 04:16:11 surfacearch systemd[1]: Starting Cleanup of Temporary Directories...
Dec 07 04:16:11 surfacearch systemd[1]: Started Cleanup of Temporary Directories.is this perhaps the key?
Dec 07 04:01:21 surfacearch kernel: xhci_hcd 0000:00:14.0: System wakeup enabled by ACPISeems like several items live on that pci USB controller
[ 0.477949] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 2
[ 2.077492] input: Microsoft Surface Type Cover Keyboard as /devices/pci0000:00/0000:00:14.0/usb1/1-3/1-3:1.0/0003:045E:07E2.0002/input/input7
[ 2.128349] input: Microsoft Surface Type Cover Mouse as /devices/pci0000:00/0000:00:14.0/usb1/1-3/1-3:1.0/0003:045E:07E2.0002/input/input8
[ 2.128520] input: Microsoft Surface Type Cover Consumer Control as /devices/pci0000:00/0000:00:14.0/usb1/1-3/1-3:1.0/0003:045E:07E2.0002/input/input9
[ 2.132243] hid-multitouch 0003:045E:07E2.0002: input,hiddev0,hidraw0: USB HID v1.11 Keyboard [Microsoft Surface Type Cover] on usb-0000:00:14.0-3/input0
[ 2.157056] input: Microsoft LifeCam Front as /devices/pci0000:00/0000:00:14.0/usb1/1-7/1-7:1.0/input/input27
[ 2.158922] input: Microsoft LifeCam Rear as /devices/pci0000:00/0000:00:14.0/usb1/1-8/1-8:1.0/input/input28
[dylan@surfacearch ~]$ lspci | grep ":14.0"
00:14.0 USB controller: Intel Corporation 8 Series USB xHCI HC (rev 04)
[dylan@surfacearch ~]$ Can anyone call, based on above dmesg, what actualy woke the thing up?
many thanks!
Offline
Well, something has changed. Maybe this is what was happening the whole time, but I don't think so.
I'm using the AUR kernel for the surfacepro3 (https://aur.archlinux.org/packages/linux-surfacepro3/) which is currently on kernel version 4.4.1-2.
I found that using the power button worked as expected with no wakes from sleep.
Closing the lid after putting to sleep would wake the device up, however - so perhaps this is what happening.
The settings in cinnamon's power management were set to 'do nothing' when lid is opened/closed, so that clearly wasn't working.
Changing the settings in cinnamon power management to 'suspend' when lid is closed seems to work as expected, with no wakeups.
I need to check if disconnecting power during sleep causes any issues with waking.
Offline