Wi-Fi (athk9) draining battery whilst in suspend

rsoul · 2015-03-01 08:31:07

For the last 4 or 5 mornings I've woken up to find my laptop has completely lost its battery charge after being suspended (lid closed). This is strange as this has never happened in all the years i've been running Arch on this hardware. The only thing I can think of is I recently changed the WIFI card.

journalctl

Feb 27 22:55:21 arch gnome-session[821]: DBG: gtk.gdk.WindowState = 40
Feb 27 22:55:21 arch gnome-session[821]: DBG: GDK_WINDOW_STATE_STICKY? True
Feb 27 22:55:21 arch gnome-session[821]: DBG: GDK_WINDOW_STATE_WITHDRAWN? False
Feb 27 22:55:21 arch gnome-session[821]: DBG: GDK_WINDOW_STATE_ABOVE? True
Feb 27 22:55:21 arch gnome-session[821]: DBG: hiding the terminal
Feb 27 23:02:36 arch chromium.desktop[1006]: [1006:1093:0227/230236:ERROR:get_updates_processor.cc(240)] PostClientToServerMessage() failed during
Feb 27 23:05:10 arch chromium.desktop[1006]: [1295,206158080:23:05:10.681626] Native Client module will be loaded at base address 0x000056ef000000
Feb 27 23:12:55 arch chromium.desktop[1006]: [1006:1033:0227/231255:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with 
Feb 28 05:48:38 arch systemd[810]: Time has been changed
Feb 28 05:48:46 arch chromium.desktop[1006]: [1006:1033:0228/054846:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with 
Feb 28 05:48:51 arch chromium.desktop[1006]: [1006:1093:0228/054851:ERROR:get_updates_processor.cc(240)] PostClientToServerMessage() failed during
Feb 28 05:49:05 arch chromium.desktop[1006]: [1006:1033:0228/054905:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with 
Feb 28 05:49:13 arch systemd[810]: Time has been changed
Feb 28 05:49:20 arch chromium.desktop[1006]: [1006:1033:0228/054920:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with 
Feb 28 05:49:23 arch chromium.desktop[1006]: [1006:1033:0228/054923:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with 
Feb 28 05:49:32 arch systemd[810]: Time has been changed
-- Reboot --
Feb 28 08:57:39 arch systemd[808]: Starting Sockets.
Feb 28 08:57:39 arch systemd[808]: Reached target Sockets.
Feb 28 08:57:39 arch systemd[808]: Starting Timers.
Feb 28 08:57:39 arch systemd[808]: Reached target Timers.
Feb 28 08:57:39 arch systemd[808]: Starting Paths.
Feb 28 08:57:39 arch systemd[808]: Reached target Paths.

Feb 28 22:07:57 arch chromium.desktop[1007]: [1122,3045329152:22:07:57.082978] Native Client module will be loaded at base address 0x00004f0a00000
Feb 28 22:23:57 arch chromium.desktop[1007]: [1144,3045329152:22:23:57.122371] Native Client module will be loaded at base address 0x00000ad100000
Feb 28 22:30:04 arch chromium.desktop[1007]: Fontconfig error: Cannot load default config file
Feb 28 22:37:10 arch chromium.desktop[1007]: [1007:1034:0228/223710:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with 
Mar 01 05:33:50 arch systemd[808]: Time has been changed
Mar 01 05:33:59 arch chromium.desktop[1007]: [1007:1034:0301/053359:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with 
Mar 01 05:34:03 arch chromium.desktop[1007]: [1007:1085:0301/053403:ERROR:get_updates_processor.cc(240)] PostClientToServerMessage() failed during
Mar 01 05:34:18 arch chromium.desktop[1007]: [1007:1034:0301/053418:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with 
Mar 01 05:34:26 arch systemd[808]: Time has been changed
Mar 01 05:34:34 arch chromium.desktop[1007]: [1166,3045329152:05:34:34.486257] Native Client module will be loaded at base address 0x000052ac00000
Mar 01 05:34:35 arch chromium.desktop[1007]: [1007:1034:0301/053435:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with 
Mar 01 05:34:43 arch systemd[808]: Time has been changed
Mar 01 05:34:56 arch chromium.desktop[1007]: [1007:1034:0301/053456:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with 
Mar 01 05:35:04 arch systemd[808]: Time has been changed
Mar 01 05:35:11 arch chromium.desktop[1007]: [1007:1034:0301/053511:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with 
Mar 01 05:35:13 arch chromium.desktop[1007]: [1007:1034:0301/053513:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with 
Mar 01 05:35:32 arch chromium.desktop[1007]: [1007:1034:0301/053532:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with 
Mar 01 05:35:40 arch systemd[808]: Time has been changed
-- Reboot --
Mar 01 08:14:57 arch systemd[810]: Starting Sockets.
Mar 01 08:14:57 arch systemd[810]: Reached target Sockets.
Mar 01 08:14:57 arch systemd[810]: Starting Paths.
Mar 01 08:14:57 arch systemd[810]: Reached target Paths.
Mar 01 08:14:57 arch systemd[810]: Starting Timers.
Mar 01 08:14:57 arch systemd[810]: Reached target Timers.
Mar 01 08:14:57 arch systemd[810]: Starting Basic System.
Mar 01 08:14:57 arch systemd[810]: Reached target Basic System.
Mar 01 08:14:57 arch systemd[810]: Starting Default.
Mar 01 08:14:57 arch systemd[810]: Reached target Default.

It seems to be waking up at 5:30ish for no reason. Any ideas? Thanks.

Last edited by rsoul (2015-03-14 21:16:55)

rsoul · 2015-03-02 06:58:19

I did some investigating and wondered if it was a bug in Chromium. Uninstalled it and moved to Chrome. Happened again this morning. Very odd really as the laptop acts normally when the screen is shut (ie suspends). Something is waking it up which shouldn't.

Mar 02 05:19:20 arch systemd[810]: Time has been changed
Mar 02 05:19:27 arch chromium.desktop[998]: [998:1025:0302/051927:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with er
Mar 02 05:19:27 arch google-chrome.desktop[28957]: [28957:28992:0302/051927:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoi
Mar 02 05:19:29 arch chromium.desktop[998]: [998:1025:0302/051929:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with er
Mar 02 05:19:29 arch google-chrome.desktop[28957]: [28957:28992:0302/051929:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoi
Mar 02 05:19:36 arch google-chrome.desktop[28957]: [28957:30354:0302/051936:ERROR:get_updates_processor.cc(240)] PostClientToServerMessage() faile
Mar 02 05:19:36 arch chromium.desktop[998]: [998:1084:0302/051936:ERROR:get_updates_processor.cc(240)] PostClientToServerMessage() failed during G
Mar 02 05:19:39 arch systemd[810]: Time has been changed
Mar 02 05:19:42 arch google-chrome.desktop[28957]: [795,3669858560:05:19:42.280368] Native Client module will be loaded at base address 0x00005ac2
Mar 02 05:19:47 arch chromium.desktop[998]: [998:1025:0302/051947:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with er
Mar 02 05:19:47 arch google-chrome.desktop[28957]: [28957:28992:0302/051947:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoi
Mar 02 05:19:56 arch systemd[810]: Time has been changed
Mar 02 05:20:03 arch google-chrome.desktop[28957]: [28957:28992:0302/052003:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoi
Mar 02 05:20:03 arch chromium.desktop[998]: [998:1025:0302/052003:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with er
Mar 02 05:20:05 arch google-chrome.desktop[28957]: [28957:28992:0302/052005:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoi
Mar 02 05:20:05 arch chromium.desktop[998]: [998:1025:0302/052005:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with er
Mar 02 05:20:24 arch chromium.desktop[998]: [998:1025:0302/052024:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with er
Mar 02 05:20:24 arch google-chrome.desktop[28957]: [28957:28992:0302/052024:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoi
Mar 02 05:20:34 arch systemd[810]: Time has been changed
Mar 02 05:20:40 arch chromium.desktop[998]: [998:1025:0302/052040:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with er
Mar 02 05:20:40 arch google-chrome.desktop[28957]: [28957:28992:0302/052040:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoi
Mar 02 05:21:01 arch chromium.desktop[998]: [998:1025:0302/052101:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with er
Mar 02 05:21:01 arch google-chrome.desktop[28957]: [28957:28992:0302/052101:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoi
-- Reboot --
Mar 02 06:55:10 arch systemd[804]: Starting Timers.
Mar 02 06:55:10 arch systemd[804]: Reached target Timers.
Mar 02 06:55:10 arch systemd[804]: Starting Paths.
Mar 02 06:55:10 arch systemd[804]: Reached target Paths.
Mar 02 06:55:10 arch systemd[804]: Starting Sockets.
Mar 02 06:55:10 arch systemd[804]: Reached target Sockets.
Mar 02 06:55:10 arch systemd[804]: Starting Basic System.
Mar 02 06:55:10 arch systemd[804]: Reached target Basic System.
Mar 02 06:55:10 arch systemd[804]: Starting Default.
Mar 02 06:55:10 arch systemd[804]: Reached target Default.

rsoul · 2015-03-02 10:13:33

Realised that the journals do not include root info:

Mar 01 22:03:38 arch systemd-logind[177]: Lid closed.
Mar 01 22:03:38 arch systemd-logind[177]: Suspending...
Mar 01 22:03:38 arch NetworkManager[160]: <info>  sleep requested (sleeping: no  enabled: yes)
Mar 01 22:03:38 arch NetworkManager[160]: <info>  sleeping...
Mar 01 22:03:38 arch NetworkManager[160]: <info>  (enp1s0): device state change: unavailable -> unmanaged (reason 'sleeping') [20 10 37]
Mar 01 22:03:38 arch NetworkManager[160]: <info>  (wlp2s0): device state change: activated -> unmanaged (reason 'sleeping') [100 10 37]
Mar 01 22:03:38 arch kernel: IPv6: ADDRCONF(NETDEV_UP): enp1s0: link is not ready
Mar 01 22:03:38 arch NetworkManager[160]: <info>  (wlp2s0): deactivating device (reason 'sleeping') [37]
Mar 01 22:03:38 arch NetworkManager[160]: <info>  (wlp2s0): canceled DHCP transaction, DHCP client pid 470
Mar 01 22:03:38 arch NetworkManager[160]: <info>  (wlp2s0): DHCPv4 state changed bound -> done
Mar 01 22:03:38 arch avahi-daemon[6206]: Withdrawing address record for fe80::2ed0:5aff:fed3:d996 on wlp2s0.
Mar 01 22:03:38 arch avahi-daemon[6206]: Withdrawing address record for 192.168.1.157 on wlp2s0.
Mar 01 22:03:38 arch avahi-daemon[6206]: Leaving mDNS multicast group on interface wlp2s0.IPv4 with address 192.168.1.157.
Mar 01 22:03:38 arch kernel: wlp2s0: deauthenticating from 84:1b:5e:da:81:a8 by local choice (Reason: 3=DEAUTH_LEAVING)
Mar 01 22:03:38 arch kernel: cfg80211: Calling CRDA to update world regulatory domain
Mar 01 22:03:38 arch NetworkManager[160]: <info>  Removing DNS information from /usr/bin/resolvconf
Mar 01 22:03:38 arch avahi-daemon[6206]: Interface wlp2s0.IPv4 no longer relevant for mDNS.
Mar 01 22:03:38 arch NetworkManager[160]: <info>  NetworkManager state is now ASLEEP
Mar 01 22:03:38 arch kernel: IPv6: ADDRCONF(NETDEV_UP): wlp2s0: link is not ready
Mar 01 22:03:38 arch dbus[161]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispat
Mar 01 22:03:38 arch dbus[161]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.nm-dispatcher.service': Unit dbus-org.freede
Mar 01 22:03:40 arch chromium.desktop[998]: [998:1025:0301/220340:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoint with er
Mar 01 22:03:40 arch google-chrome.desktop[28957]: [28957:28992:0301/220340:ERROR:connection_factory_impl.cc(344)] Failed to connect to MCS endpoi
Mar 01 22:03:40 arch systemd[1]: Starting Sleep.
Mar 01 22:03:40 arch systemd[1]: Reached target Sleep.
Mar 01 22:03:40 arch systemd[1]: Starting Suspend...
Mar 01 22:03:40 arch systemd-sleep[30369]: Suspending system...
Mar 02 05:19:20 arch kernel: PM: Syncing filesystems ... done.
Mar 02 05:19:20 arch kernel: PM: Preparing system for mem sleep
Mar 02 05:19:20 arch kernel: Freezing user space processes ... (elapsed 0.002 seconds) done.
Mar 02 05:19:20 arch kernel: Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
Mar 02 05:19:20 arch kernel: PM: Entering mem sleep
Mar 02 05:19:20 arch kernel: Suspending console(s) (use no_console_suspend to debug)
Mar 02 05:19:20 arch kernel: sd 0:0:0:0: [sda] Synchronizing SCSI cache
Mar 02 05:19:20 arch kernel: sd 0:0:0:0: [sda] Stopping disk
Mar 02 05:19:20 arch kernel: PM: suspend of devices complete after 195.193 msecs
Mar 02 05:19:20 arch kernel: PM: late suspend of devices complete after 13.270 msecs
Mar 02 05:19:20 arch kernel: ehci-pci 0000:00:1d.0: System wakeup enabled by ACPI
Mar 02 05:19:20 arch kernel: ehci-pci 0000:00:1a.0: System wakeup enabled by ACPI
Mar 02 05:19:20 arch kernel: PM: noirq suspend of devices complete after 13.402 msecs
Mar 02 05:19:20 arch kernel: ACPI: Preparing to enter system sleep state S3
Mar 02 05:19:20 arch kernel: PM: Saving platform NVS memory
Mar 02 05:19:20 arch kernel: Disabling non-boot CPUs ...
Mar 02 05:19:20 arch kernel: kvm: disabling virtualization on CPU1
Mar 02 05:19:20 arch kernel: smpboot: CPU 1 is now offline
Mar 02 05:19:20 arch kernel: ACPI: Low-level resume complete
Mar 02 05:19:20 arch kernel: PM: Restoring platform NVS memory
Mar 02 05:19:20 arch kernel: CPU0 microcode updated early to revision 0x4, date = 2013-06-28
Mar 02 05:19:20 arch kernel: Enabling non-boot CPUs ...
Mar 02 05:19:20 arch kernel: x86: Booting SMP configuration:
Mar 02 05:19:20 arch kernel: smpboot: Booting Node 0 Processor 1 APIC 0x4
Mar 02 05:19:20 arch kernel: CPU1 microcode updated early to revision 0x4, date = 2013-06-28
Mar 02 05:19:20 arch kernel: kvm: enabling virtualization on CPU1
Mar 02 05:19:20 arch kernel: CPU1 is up
Mar 02 05:19:20 arch kernel: ACPI: Waking up from system sleep state S3
Mar 02 05:19:20 arch kernel: ehci-pci 0000:00:1a.0: System wakeup disabled by ACPI
Mar 02 05:19:20 arch kernel: ehci-pci 0000:00:1d.0: System wakeup disabled by ACPI
Mar 02 05:19:20 arch kernel: PM: noirq resume of devices complete after 13.820 msecs
Mar 02 05:19:20 arch kernel: PM: early resume of devices complete after 2.185 msecs
Mar 02 05:19:20 arch kernel: mei_me 0000:00:16.0: irq 25 for MSI/MSI-X

Last edited by rsoul (2015-03-02 10:13:52)

lucke · 2015-03-02 17:53:50

See if disabling Wake-on-LAN changes anything.

Do you have any peripherals connected? If so, see if disconnecting them helps.

rsoul · 2015-03-02 19:05:01

No peripherals attached. And I don't think it's a WOL issue. I think I may have solved it using this thread

 # echo 'EHC1' > /proc/acpi/wakeup

Possibly the bluetooth chip on the new wifi card. Would fit with the timing of the behaviour. I'll find out tomorrow morning. Wish me luck.

lucke · 2015-03-02 19:13:44

I wish you lucke.

rsoul · 2015-03-02 19:33:36

Good one.

rsoul · 2015-03-10 10:33:16

Right, having no luck with this. I have the funny feeling that what is happening is the computer is waking up because the battery is running out. Since this behaviour has only happened since upgrading the wifi chip I suspect that it is the issue. Any ideas on working out what is running down the battery while in suspend?

Interesting?

Last edited by rsoul (2015-03-10 12:03:34)

rsoul · 2015-03-11 07:27:02

I was correct. It is the WIFI card. I physically removed it last night, put the computer into suspend by closing the lid, and in the morning there was still 85% charge.

Network controller: Qualcomm Atheros AR9462 Wireless Network Adapter (rev 01)

iwconfig:

wlp2s0    IEEE 802.11abgn  ESSID:"onewireless5g"  
          Mode:Managed  Frequency:5.22 GHz  Access Point: 84:1B:5E:DA:81:A8   
          Bit Rate=270 Mb/s   Tx-Power=15 dBm   
          Retry short limit:7   RTS thr:off   Fragment thr:off
          Power Management:off
          Link Quality=63/70  Signal level=-47 dBm  
          Rx invalid nwid:0  Rx invalid crypt:0  Rx invalid frag:0
          Tx excessive retries:0  Invalid misc:42   Missed beacon:0

As for WOL...

ethtool wlp2s0
Settings for wlp2s0:
        Link detected: yes

So the question is, how do I stop the WIFI card draining the battery in suspend? Thanks.

Maybe I need to turn on power saving? https://wiki.archlinux.org/index.php/Wi … r_saving_2

Last edited by rsoul (2015-03-11 07:38:19)

lucke · 2015-03-11 16:23:46

Maybe unloading the wifi module before suspending would help.

rsoul · 2015-03-11 16:26:21

Worth a try I guess. Thanks for the suggestion Lucke.

rsoul · 2015-03-12 07:10:20

Did

 modprobe -r ath9k

wifi seemingly turned off. Laptop still lost battery after massive battery drain. I may be forced to move back to my old WIFI card if this can't be fixed. Seems a shame really because during the day there is no problem with this new n card. The only problem is suspend.

rsoul · 2015-03-13 11:46:55

I'm at a bit of a loss as how to proceed. I'm thinking next stop athk9 development mailing list?

Arch Linux

#1 2015-03-01 08:31:07

Wi-Fi (athk9) draining battery whilst in suspend

#2 2015-03-02 06:58:19

Re: Wi-Fi (athk9) draining battery whilst in suspend

#3 2015-03-02 10:13:33

Re: Wi-Fi (athk9) draining battery whilst in suspend

#4 2015-03-02 17:53:50

Re: Wi-Fi (athk9) draining battery whilst in suspend

#5 2015-03-02 19:05:01

Re: Wi-Fi (athk9) draining battery whilst in suspend

#6 2015-03-02 19:13:44

Re: Wi-Fi (athk9) draining battery whilst in suspend

#7 2015-03-02 19:33:36

Re: Wi-Fi (athk9) draining battery whilst in suspend

#8 2015-03-10 10:33:16

Re: Wi-Fi (athk9) draining battery whilst in suspend

#9 2015-03-11 07:27:02

Re: Wi-Fi (athk9) draining battery whilst in suspend

#10 2015-03-11 16:23:46

Re: Wi-Fi (athk9) draining battery whilst in suspend

#11 2015-03-11 16:26:21

Re: Wi-Fi (athk9) draining battery whilst in suspend

#12 2015-03-12 07:10:20

Re: Wi-Fi (athk9) draining battery whilst in suspend

#13 2015-03-13 11:46:55

Re: Wi-Fi (athk9) draining battery whilst in suspend

Board footer