Extensive battery drain on RTM

Bug #1372413 reported by Tomas Öqvist on 2014-09-22
88
This bug affects 13 people
Affects Status Importance Assigned to Milestone
Canonical System Image
Critical
Pat McGowan
powerd
Undecided
Unassigned
powerd (Ubuntu)
Undecided
Unassigned

Bug Description

Mako, RTM 1

Since upgrading to RTM the battery life is really poor. What used to be a battery drain of 5-10% per hour (which is still high) is now 10-15% per hour. Sometimes the phone runs really hot, so there seem to be something going on in the background that is consuming power. I mostly have bluetooth, GPS (which isn't always working), wifi and cellular on, but that's no difference from when I was running 'devel-proposed' with MultiROM with much less battery consumption.

As an example, I started with a full charge at 7am. After some web surfing (<15 mins) and watching a couple of youtube videos (on wifi) battery was down to 66% at 9:15. That's 34% in just over two hours! I recharged again before lunch and had the phone idle until coming back 1 hour and 45 mins later to find only 75% of battery left, this time without the phone running particularly hot.

Zoltan Balogh (bzoltan) on 2014-10-01
Changed in ubuntu-ui-toolkit (Ubuntu):
status: New → Invalid
affects: ubuntu-ui-toolkit (Ubuntu) → powerd (Ubuntu)
Changed in powerd (Ubuntu):
status: Invalid → New
Tomas Öqvist (tomoqv) wrote :

This issue seems to be resolved in later rtm-proposed releases (I am now on mako #71). My battery drain now mostly varies between 4-5 up to 8-9 per cent an hour with light to moderate use.

Launchpad Janitor (janitor) wrote :

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

Changed in powerd (Ubuntu):
status: New → Confirmed
Pat McGowan (pat-mcgowan) wrote :

Reviving this bug based on recent anecdotal reports that battery life has degraded

Folks who experience it can do several things to provide data:
1 - check the battery page in settings and see the battery level history, for example did it discharge overnight
2 - provide the syslog which will show whether the system is properly suspending
3 - install suspend-blocker on your desktop
sudo add-apt-repository ppa:colin-king/white
sudo apt-get update
sudo apt-get install suspend-blocker

Copy the syslog from the phone
adb pull /var/log/syslog

and run the command
 suspend-blocker -b -r -H < syslog

Pat McGowan (pat-mcgowan) wrote :

adding here to track

Changed in canonical-devices-system-image:
milestone: none → ww03-2015
status: New → Confirmed
Colin Ian King (colin-king) wrote :

Also, it would be useful to capture activity of the system using the following over a 10 minute period

Still using ppa:colin-king/white:

sudo apt-get install eventstat cpustat fnotifystat forkstat

sudo eventstat 10 60 > eventstat.log

(10 seconds of sampling, 60 x a second)

And see if the CPU is busy:

sudo cpustat 10 60 > cpustat.log

And see if the file system is busy:

sudo fnotifystat 10 60 > fnotifystat.log

And see if there is excessive thread or process creation:

sudo forkstat -D 600 > forkstat.log

Joe Odukoya (jodukoya) wrote :

My phone battery was virtually flat again this morning.
I'll see if I can get someone to help with the tech stuff above - meanwhile though here is a screen-grab of my battery discharge graph from settings which clearly shows a continuous (and fairly rapid) discharge overnight despite being, supposedly, idle.

Note: Although the charge level says 26% it had actually descended to 7% when I woke it up this morning. I put it on charge before it occurred to me to take a screenshot.

Pat McGowan (pat-mcgowan) wrote :

Mako running 160 out of battery, lost 50% charge overnight
While it seems to suspend successfully the majority of the time it is not suspended very long, 90% are less than a min

Pat McGowan (pat-mcgowan) wrote :
Colin Ian King (colin-king) wrote :

I compared a 10 minute sleep from an image from pre-Christmas to the latest RTM image and I see better deep suspend stats with the latest image (see attached).

If Thomas can attach all the syslog files from /var/log/syslog we can parse this with suspend-blocker and get an idea of what's been going on. The stats you attached Pat look reasonable for the mako, it does pop out of deep suspend every 60 or so seconds for a short while to handle events from the modem front end.

Colin Ian King (colin-king) wrote :

I compared a 10 minute sleep from an image from pre-Christmas to the latest RTM image and I see better deep suspend stats with the latest image (see attached).

If Thomas can attach all the syslog files from /var/log/syslog we can parse this with suspend-blocker and get an idea of what's been going on. The stats you attached Pat look reasonable for the mako, it does pop out of deep suspend every 60 or so seconds for a short while to handle events from the modem front end.

Colin Ian King (colin-king) wrote :

I compared 10 minutes of file access activity (old pre-Christmas image vs lastest RTM image) and I'm seeing a lot more udevd activity on /lib/udev/rules.d, /etc/modprobe.d and /etc/group.

See attached files (spreadsheet and old vs new file activity logs).

Colin Ian King (colin-king) wrote :

I also compared 10 minutes of file process wakeup activity (old pre-Christmas image vs lastest RTM image) and I'm seeing little different between old vs new, so no obvious regressions there.

See attached files (spreadsheet and old vs new file activity logs).

Ricardo Salveti (rsalveti) wrote :

It's weird that we got so much more activity on /lib/udev/rules.d, /etc/modprobe.d and /etc/group, wonder what might be causing that.

Colin Ian King (colin-king) wrote :

I've written a bash script to periodically grab battery capacity levels over some of this afternoon and projected the expected duration (making an assumption the battery drain is linear, which it is not, i know that). Anyhow, I predict > 30+ hours of idle on a default clean install on deep sleep. See attached spreadsheet. I will update the bug with the complete data tomorrow.

Changed in canonical-devices-system-image:
milestone: ww03-2015 → ww05-2015
Changed in canonical-devices-system-image:
status: Confirmed → In Progress
Colin Ian King (colin-king) wrote :

With wifi associated to a fairly "busy" AP that produces regular beacon intervals with CTS protection mode enabled and also phone data enabled I'm seeing ~24+ hours on deep sleep idle.

With wifi enabled, I'm seeing ~7.5 wifi related wakeups per minute. I then disabled wifi and these wakeups disappear. So the bottom line is that wifi in deep sleep is the root cause of extraneous wakeups. Now depending on how busy the AP is and the kinds of packets, it may cause more or less wakeups, hence different drain characteristics.

I'll recharge the phone and see how the wifi disabled case changes the battery drain rate.

Attached is two-page spreadsheet of my drain results and also stats on wakeups from deep sleep caused by wifi related wakeup events.

Pat McGowan (pat-mcgowan) wrote :

comments from Colin

I've worked through all the images now and can see that deep suspend
sometimes fails to work completely because of a series of COMM events
that cause excessive wakeups. Typically, in this scenario, one sees
300-700 CONN wakeup events over a 300 second interval. This either
prevents deep suspend from occurring, or wakes deep suspend almost
immediately it occurs. In this scenario, instead of a 7-10mA deep sleep,
I observe ~70-100mA being drawn.

I can trigger this on all the images I've now tested. One easy way to
trigger this is via the USB adb connection and yanking out the cable and
then going into deep sleep without exiting adb and then going into deep
sleep. I also believe going into deep sleep while connected to adb and
then yanking out the USB cable also can cause this issue.

If I recall correctly, the CONN event relates to the USB connections and
does seem to correlate with this adb connection over USB.

This explains the difficulty I had bisecting the issue earlier on. I
believe I may have been careless in putting the device into deep sleep
with USB connected, and then disconnecting before measuring deep sleep
current with the multimeter.

So, for the anecdotal reports of battery life being reduced:

a) It may be this USB issue causing deep sleep to be interrupted by
   CONN events.

b) It may be something entirely different.

it's hard to say. But I do now have evidence that between revision 153
and 202 there are not any observable changes in deep sleep characteristics.

Pat McGowan (pat-mcgowan) wrote :

Results today on my Krillin, each sample is around an hour
(Mako shows 2% suspends aborted while associated.)

With no AP associated:

Suspend blocking wakelocks:
  None

Resume wakeup causes:
  CCIF_MD 96 78.69%
  EINT 26 21.31%

Suspends:
  5 suspends aborted (3.94%).
  122 suspends succeeded (96.06%).
  total time: 4044.799050 seconds (72.17%).
  minimum: 0.104611 seconds.
  maximum: 140.608969 seconds.
  mean: 33.154091 seconds.
  mode: 16.000000 seconds.
  median: 16.011104 seconds.

Time between successful suspends:
  total time: 1559.784028 seconds (27.83%).
  minimum: 0.447323 seconds.
  maximum: 216.242661 seconds.
  mean: 12.890777 seconds.
  mode: 1.000000 seconds.
  median: 0.993829 seconds.

With an AP associated:

Suspend blocking wakelocks:
  None

Resume wakeup causes:
  CCIF_MD 36 56.25%
  CONN 16 25.00%
  EINT 12 18.75%

Suspends:
  15 suspends aborted (18.99%).
  64 suspends succeeded (81.01%).
  total time: 2291.906108 seconds (71.91%).
  minimum: 0.103741 seconds.
  maximum: 139.054901 seconds.
  mean: 35.811033 seconds.
  mode: 16.000000 seconds.
  median: 16.995592 seconds.

Time between successful suspends:
  total time: 895.264443 seconds (28.09%).
  minimum: 0.047539 seconds.
  maximum: 165.792165 seconds.
  mean: 14.210547 seconds.
  mode: 1.000000 seconds.
  median: 0.992057 seconds.

Pat McGowan (pat-mcgowan) wrote :

Mako results:

Suspend blocking wakelocks:
  power-supply 1 50.00%
  wlan 1 50.00%

Resume wakeup causes:
  None

Suspend failure causes:
  late suspend wakelock 2 66.67%

uspends:
  4 suspends aborted (2.01%).
  195 suspends succeeded (97.99%).
  total time: 2547.743260 seconds (40.09%).
  minimum: 0.368175 seconds.
  maximum: 31.014737 seconds.
  mean: 13.065350 seconds.
  mode: 31.000000 seconds.
  median: 11.993385 seconds.

Time between successful suspends:
  total time: 3807.344009 seconds (59.91%).
  minimum: 0.000152 seconds.
  maximum: 3074.792906 seconds.
  mean: 19.625485 seconds.
  mode: 0.000000 seconds.
  median: 0.009834 seconds.

Pat McGowan (pat-mcgowan) wrote :
Pat McGowan (pat-mcgowan) wrote :
Pat McGowan (pat-mcgowan) wrote :
Changed in canonical-devices-system-image:
milestone: ww05-2015 → ww07-2015
Changed in canonical-devices-system-image:
importance: Undecided → Critical
Pat McGowan (pat-mcgowan) wrote :

I wrote a script that parses the contents of /var/lib/upower//history-charge-generic_id.dat

The recent results on krillin:
Lost 43.000 percent over 18.33 hours, 2.34 percent per hr
Lost 5.000 percent over 1.69 hours, 2.94 percent per hr
Lost 58.000 percent over 15.97 hours, 3.62 percent per hr
Lost 22.000 percent over 3.86 hours, 5.68 percent per hr

and mako
Lost 68.000 percent over 18.33 hours, 3.70 percent per hr
Lost 32.000 percent over 21.50 hours, 1.48 percent per hr
Lost 5.000 percent over .17 hours, 28.75 percent per hr
Lost 27.000 percent over 16.50 hours, 1.63 percent per hr
Lost 11.000 percent over 3.06 hours, 3.58 percent per hr
Lost 17.000 percent over 13.33 hours, 1.27 percent per hr
Lost 14.000 percent over 4.19 hours, 3.33 percent per hr
Lost 2.000 percent over .42 hours, 4.67 percent per hr
Lost 85.000 percent over 14.44 hours, 5.88 percent per hr
Lost 26.000 percent over 8.77 hours, 2.96 percent per hr
Lost 60.000 percent over 11.44 hours, 5.24 percent per hr
Lost 55.000 percent over 21.98 hours, 2.50 percent per hr
Lost 3.000 percent over .07 hours, 38.43 percent per hr
Lost 23.000 percent over 2.27 hours, 10.11 percent per hr

Pat McGowan (pat-mcgowan) wrote :

In a dupe of this bug they report around 4% drain per hour (47% over 12 hrs)

I am seeing an average, including usage not just when idle, of 3.2% on krillin and 3.1% on mako
Seeing as low as 2.3% when idle on krillin and as low as 1.3% when idle on mako, all percent drop per hour.

Wifi, BT, GPS, 3G all enabled

Pat McGowan (pat-mcgowan) wrote :

Mako with wifi turned off
Lost 19.000 percent over 14.88 hours, 1.27 percent per hr
it was 10% drained after 13 hrs idle overnight

Pat McGowan (pat-mcgowan) wrote :

Krillin with wifi and bt off
Lost 36.000 percent over 20.76 hours, 1.73 percent per hr

Pat McGowan (pat-mcgowan) wrote :

(see also comment #5 above)

sudo add-apt-repository ppa:colin-king/white
sudo apt-get update
sudo apt-get install cpustat

cpustat blocks on a select() system call. While the phone is not suspended it will log all CPU process activity every 2 seconds. This will consume ~0.25% of the CPU, so in real terms that's almost nothing. cpustat will not block the phone from deep sleep. The kernel will freeze it when the phone goes into deep sleep. please do the following:

adb into the phone and type:

nohup cpustat 2 > cpustat.log &
exit

then disconnect the USB and let it run.

Once the phone is drained, or whenever you want to stop the test, copy the cpustat.log over and we can analyze it.

tags: added: battery
Pat McGowan (pat-mcgowan) wrote :

I had a drainoff last night on mako and had cpustat running, which points at upowerd
A number of samples like the following :

 %CPU %USR %SYS PID Task
 17.76 16.87 0.90 1493 /usr/lib/upower/upowerd
  0.80 0.40 0.40 4319 cpustat
  0.80 0.10 0.70 1180 /system/bin/mpdecision
  0.60 0.00 0.60 134 [mmcqd/0]
  0.50 0.00 0.50 234 [jbd2/mmcblk0p23]
  0.50 0.00 0.50 29761 [kworker/0:3]
  0.30 0.00 0.30 971 /lib/systemd/systemd-udevd
  0.30 0.30 0.00 2579 [kworker/0:2]
  0.30 0.20 0.10 2724 unity8
  0.20 0.20 0.00 848 dbus-daemon
  0.10 0.00 0.10 776 rsyslogd
  0.10 0.10 0.00 1593 init
  0.10 0.00 0.10 1179 /system/bin/thermald
  0.10 0.10 0.00 1 /sbin/init
  0.10 0.00 0.10 23 [sync_supers]
  0.10 0.10 0.00 750 upstart-file-bridge
  0.10 0.00 0.10 1346 [MC_Thread]
  0.10 0.00 0.10 21367 [kworker/u:0]
  0.10 0.00 0.10 2702 /usr/lib/arm-linux-gnueabihf/indicator-power/indicator-power-service

Pat McGowan (pat-mcgowan) wrote :

Syslog showing lots of wmlan and mmc reports starting at 17:53 when I left the house and out of wifi range.

Colin Ian King (colin-king) wrote :

Any chance of getting that syslog to see what's going on?

Colin Ian King (colin-king) wrote :

FYI, For my tests, I am reading the battery capacity directly, just to keep it as light weight as possible:

#!/bin/sh
rm -f battery.log
while true
do
 c=$(cat /sys/devices/platform/battery/power_supply/battery/capacity)
 d=$(date "+%d/%m/%Y %H:%M:%S")
 echo "$d $c" >> battery.log
 sleep 2
done

Colin Ian King (colin-king) wrote :

Pat, do you mind attaching the entire cpustat.log so I spot any specific trends? Thanks

Colin Ian King (colin-king) wrote :

We could possibly attach health-check to powerd to see what activity is going.

E.g.

health-check -r -w -W -f -c -p upowerd -d 3600 > health-check.log

..that will attach health-check for 1 hour and dump the results into health-check.log.

Colin

Pat McGowan (pat-mcgowan) wrote :

The complete cpustat.log for that event

@colin do you have something to intelligently parse these files?

Pat McGowan (pat-mcgowan) wrote :

and the syslog I somehow did't attach

Colin Ian King (colin-king) wrote :

Pat, I use something such like the following awk script to parse the data:

{
        if ((NF == 5) && ($4 != "PID")) {
                total[$4] += $1
                usr[$4] += $2
                sys[$4] += $3
                cmd[$4] = $5
        }
        if ((NF == 5) && ($4 == "PID"))
                n++
}
END {
        for (i in total)
                printf "%10.2f %10.2f %10.2f %s\n", total[i], usr[i], sys[i], cmd[i]
}

awk -f cpustat.awk < cpustat.log | sort -nr | head -20

  20400.32 19276.85 1123.57 /usr/lib/upower/upowerd
   3503.49 2570.89 932.58 unity8
   3243.72 870.17 2373.55 cpustat
   2911.39 1710.02 1201.39 /lib/systemd/systemd-udevd
   2207.87 182.06 2025.80 /system/bin/mpdecision
   2133.32 2012.62 120.71 dbus-daemon
   2125.58 1751.23 374.36 messaging-app
   1280.77 0.00 1280.77 [mmcqd/0]
    675.34 0.00 675.34 [jbd2/mmcblk0p23]
    449.83 159.82 289.96 unity-system-compositor
    412.58 312.51 100.07 NetworkManager
    372.17 206.53 165.64 init
    355.62 259.23 96.40 /sbin/init
    323.53 0.00 323.53 [MC_Thread]
    315.88 278.62 37.27 /usr/bin/powerd
    310.32 268.82 41.50 /usr/lib/arm-linux-gnueabihf/indicator-power/indicator-power-service
    267.14 237.61 29.54 maliit-server
    228.89 12.30 216.59 /sbin/healthd
    200.54 169.84 30.70 /custom/vendor/here/location-provider/bin/arm-linux-gnueabihf/posclientd
    182.56 14.76 167.79 /init

So it does seem that upowerd is consuming the most cycles. Attached is a spreadsheet and a graph from the raw stats

Colin Ian King (colin-king) wrote :

So there is a rise of activity with systemd-udev at the same time that upowerd gets busy too

Colin Ian King (colin-king) wrote :

I've correlated each processes against the spike in activity for upowerd and also see that mpdecision and systemd-udevd also change their behaviors at that transition. See attached spreadsheet.

Colin Ian King (colin-king) wrote :

I noticed that at this point, the syslog shows and incoming call occurred. After that, the phone does NOT deep suspend at all. Eventually, the phone drains at 03:55:33 on the 7th of Feb. So I think somebody needs to look at the way incoming calls seem to block deep suspend.

Feb 6 17:12:05 ubuntu-phablet kernel: [ 1535.537188] suspend: abort suspend
Feb 6 17:12:06 ubuntu-phablet powerd[948]: message repeated 3 times: [ signalling activity via HAL]
Feb 6 17:12:06 ubuntu-phablet powerd[948]: incoming call
Feb 6 17:12:06 ubuntu-phablet kernel: [ 1537.243247] request_suspend_state: wakeup (3->0) at 1537348691404 (2015-02-06 22:12:06.717124433 UTC)
Feb 6 17:12:06 ubuntu-phablet kernel: [ 1537.243399] [Touch D]touch enable
Feb 6 17:12:06 ubuntu-phablet kernel: [ 1537.249046] mipi_dsi_panel_power: mipi lcd function started status = 1
Feb 6 17:12:06 ubuntu-phablet kernel: [ 1537.252739] mipi_dsi_panel_power : reset start.
Feb 6 17:12:06 ubuntu-phablet kernel: [ 1537.278162] mipi_lgit_lcd_on started
Feb 6 17:12:06 ubuntu-phablet kernel: [ 1537.335418] mipi_lgit_lcd_on finished
Feb 6 17:12:06 ubuntu-phablet kernel: [ 1537.341950] lm3530_backlight_on, ++ lm3530_backlight_on

On Monday, February 9, 2015, Colin Ian King <email address hidden>
wrote:
> I've correlated each processes against the spike in activity for upowerd
> and also see that mpdecision and systemd-udevd also change their
> behaviors at that transition. See attached spreadsheet.

mpdecision is the proprietary service that changes the cpu clock and
enable/disable the other cpus, so that is just a side effect of others
taking more cpu processing.

> ** Attachment added: "upowerd-procs.ods"
>
https://bugs.launchpad.net/ubuntu/+source/powerd/+bug/1372413/+attachment/4315533/+files/upowerd-procs.ods
>
> --
> You received this bug notification because you are subscribed to powerd
> in Ubuntu.
> https://bugs.launchpad.net/bugs/1372413
>
> Title:
> Extensive battery drain on RTM
>
> Status in the base for Ubuntu mobile products:
> In Progress
> Status in powerd package in Ubuntu:
> Confirmed
>
> Bug description:
> Mako, RTM 1
>
> Since upgrading to RTM the battery life is really poor. What used to
> be a battery drain of 5-10% per hour (which is still high) is now
> 10-15% per hour. Sometimes the phone runs really hot, so there seem to
> be something going on in the background that is consuming power. I
> mostly have bluetooth, GPS (which isn't always working), wifi and
> cellular on, but that's no difference from when I was running 'devel-
> proposed' with MultiROM with much less battery consumption.
>
> As an example, I started with a full charge at 7am. After some web
> surfing (<15 mins) and watching a couple of youtube videos (on wifi)
> battery was down to 66% at 9:15. That's 34% in just over two hours! I
> recharged again before lunch and had the phone idle until coming back
> 1 hour and 45 mins later to find only 75% of battery left, this time
> without the phone running particularly hot.
>
> To manage notifications about this bug go to:
>
https://bugs.launchpad.net/canonical-devices-system-image/+bug/1372413/+subscriptions
>

--
Ricardo Salveti de Araujo

Ricardo Salveti (rsalveti) wrote :

On Monday, February 9, 2015, Colin Ian King <email address hidden>
wrote:
> I noticed that at this point, the syslog shows and incoming call
> occurred. After that, the phone does NOT deep suspend at all.
> Eventually, the phone drains at 03:55:33 on the 7th of Feb. So I think
> somebody needs to look at the way incoming calls seem to block deep
> suspend.

I dont see nothing major from our userspace though. Pat, mind enabling
powerd debug in the powerd upstart job? Just remove the comment in there
and reboot, that should help understanding what is going on.

> Feb 6 17:12:05 ubuntu-phablet kernel: [ 1535.537188] suspend: abort
suspend
> Feb 6 17:12:06 ubuntu-phablet powerd[948]: message repeated 3 times: [
signalling activity via HAL]
> Feb 6 17:12:06 ubuntu-phablet powerd[948]: incoming call
> Feb 6 17:12:06 ubuntu-phablet kernel: [ 1537.243247]
request_suspend_state: wakeup (3->0) at 1537348691404 (2015-02-06
22:12:06.717124433 UTC)
> Feb 6 17:12:06 ubuntu-phablet kernel: [ 1537.243399] [Touch D]touch
enable
> Feb 6 17:12:06 ubuntu-phablet kernel: [ 1537.249046]
mipi_dsi_panel_power: mipi lcd function started status = 1
> Feb 6 17:12:06 ubuntu-phablet kernel: [ 1537.252739]
mipi_dsi_panel_power : reset start.
> Feb 6 17:12:06 ubuntu-phablet kernel: [ 1537.278162] mipi_lgit_lcd_on
started
> Feb 6 17:12:06 ubuntu-phablet kernel: [ 1537.335418] mipi_lgit_lcd_on
finished
> Feb 6 17:12:06 ubuntu-phablet kernel: [ 1537.341950]
lm3530_backlight_on, ++ lm3530_backlight_on
>
> --
> You received this bug notification because you are subscribed to powerd
> in Ubuntu.
> https://bugs.launchpad.net/bugs/1372413
>
> Title:
> Extensive battery drain on RTM
>
> Status in the base for Ubuntu mobile products:
> In Progress
> Status in powerd package in Ubuntu:
> Confirmed
>
> Bug description:
> Mako, RTM 1
>
> Since upgrading to RTM the battery life is really poor. What used to
> be a battery drain of 5-10% per hour (which is still high) is now
> 10-15% per hour. Sometimes the phone runs really hot, so there seem to
> be something going on in the background that is consuming power. I
> mostly have bluetooth, GPS (which isn't always working), wifi and
> cellular on, but that's no difference from when I was running 'devel-
> proposed' with MultiROM with much less battery consumption.
>
> As an example, I started with a full charge at 7am. After some web
> surfing (<15 mins) and watching a couple of youtube videos (on wifi)
> battery was down to 66% at 9:15. That's 34% in just over two hours! I
> recharged again before lunch and had the phone idle until coming back
> 1 hour and 45 mins later to find only 75% of battery left, this time
> without the phone running particularly hot.
>
> To manage notifications about this bug go to:
>
https://bugs.launchpad.net/canonical-devices-system-image/+bug/1372413/+subscriptions
>

--
Ricardo Salveti de Araujo

Pat McGowan (pat-mcgowan) wrote :

ongoing so assigning to last milestone

Changed in canonical-devices-system-image:
milestone: ww07-2015 → ww13-2015
Changed in canonical-devices-system-image:
assignee: nobody → Pat McGowan (pat-mcgowan)
Ricardo Salveti (rsalveti) wrote :

Looking at the logs, it seems there are 3 patterns atm (on mako):

1 - Wifi driver failing to suspend frequently:
Feb 6 12:07:20 ubuntu-phablet kernel: [116497.506926] suspend: enter suspend
Feb 6 12:07:20 ubuntu-phablet kernel: [116497.506956] PM: suspend entry 2015-02-06 17:07:20.782768475 UTC
Feb 6 12:07:20 ubuntu-phablet kernel: [116497.506987] PM: Syncing filesystems...
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.583898] Freezing user space processes ... (elapsed 0.002 seconds) done.
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.605965] sync done.
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.827085] Freezing remaining freezable tasks ... (elapsed 0.003 seconds) done.
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.830564] Suspending console(s) (use no_console_suspend to debug)
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.842742] msm_fb_ext_suspend: Turning off HPD circuitry
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.870301] wlan: [12747:E :HDD] hdd_is_apps_power_collapse_allowed: do not allow APPS power collapse-pmcState = 1 scanRspPending = 0 inMiddleOfRoaming = 0
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.870332] wlan: [12747:E :HDD] wlan_suspend: Fail wlan suspend: not in IMPS/BMPS
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.870332] wlan: [12747:F :HDD] hddDevSuspendHdlr: Not able to suspend wlan
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.870362] dpm_run_callback(): platform_pm_suspend+0x0/0x64 returns -1
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.870362] PM: Device wcnss_wlan.0 failed to suspend: error -1
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.870362] PM: Some devices failed to suspend
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.872041] msm_fb_ext_resume: Turning on HPD circuitry
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.873476] PM: resume of devices complete after 3.051 msecs
Feb 6 12:07:21 ubuntu-phablet wpa_supplicant[6910]: rfkill: WLAN unblocked
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.875459] Restarting tasks ... done.
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.897098] PM: suspend exit 2015-02-06 17:07:21.172813771 UTC
Feb 6 12:07:21 ubuntu-phablet kernel: [116497.897098] suspend: exit suspend, ret = -1 (2015-02-06 17:07:21.172813771 UTC)

2 - Battery -> udev -> Upower heavily consuming the CPU

3 - Device not even trying to suspend anymore after receiving a call

Ricardo Salveti (rsalveti) wrote :

1 - For the wifi driver there is really not much to do, also an issue with Android and it seems to be in the latest kernel tree from google as well (need to properly check with krillin to see if a similar issue can be found in there).

Ricardo Salveti (rsalveti) wrote :

3 - Can't really reproduce when testing with my device, so created the following MR to enable debug in powerd by default (safe as it's really not printing much more because of that, but should give enough to find out why our userspace is not even trying to suspend): https://code.launchpad.net/~rsalveti/powerd/enable_debug_default/+merge/250249

Ricardo Salveti (rsalveti) wrote :

After checking the suspend logic during this weekend, I ended up with 2 remaining bugs that are probably helping battery drain:

Bug 1435109 - Push-client frequently blocking phone suspend
Bug 1434379 - GPS always active when a scope that uses location is in the background

Pat McGowan (pat-mcgowan) wrote :

I am closing this master bug since all the referenced fixes have been made.
Idle rate is now sub 1% per hr drain on Krillin
These fixes are in the upcoming update

Changed in powerd (Ubuntu):
status: Confirmed → Fix Released
Changed in powerd:
status: New → Fix Released
Changed in canonical-devices-system-image:
status: In Progress → Fix Released
milestone: ww13-2015 → ww13-ota
To post a comment you must log in.