1130725 - Flame battery only lasts half a day

Status: RESOLVED WORKSFORME

(Firefox OS Graveyard :: General, defect)

Description

[Ben Francis [:benfrancis]]

With a fresh flash of the v188 base image (latest publicly available image) + shallow flash of latest 2.2 production build, my Flame's battery still consistently only lasts half a day during normal use.

I would expect a smartphone to last at least a full day of usage.

I would argue we can not ship a release for our reference device which doesn't meet this basic bar of quality, so nominating as a 2.2 blocker.

Comment 1

[Gregor Wagner [:gwagner]]

can you see if a process is using a lot of CPU even when the phone is idle? Is any app using GPS?

Comment 2

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Do you use a second SIM card or the SIM card with the second slot? Bug 1121029 shows ~40%/day drain for idle.

Comment 3

[Gabriele Svelto [:gsvelto] (PTO)]

Same here, I've noticed that having the data connection on seems to trigger this behavior. Without data connectivity the battery lasts noticeably longer while idling.

Comment 4

[Ben Francis [:benfrancis]]

I'm not using a second SIM card at the moment, but I do have data turned on. I can try turning it off for a day.

Any idea what /system/bin/sh might be using 50% CPU for whilst idle? Everything seems OK immediately after boot, but after a day's usage I spotted this. Will keep an eye on it to see how reproducible it is.

User 50%, System 2%, IOW 0%, IRQ 0%
User 312 + Nice 0 + Sys 13 + Idle 289 + IOW 0 + IRQ 0 + SIRQ 0 = 614

  PID PR CPU% S  #THR     VSS     RSS PCY UID      Name
  312  1  50% R     1    972K    436K     shell    /system/bin/sh
12018  0   1% R     1   1312K    528K     root     top
  940  0   0% S    18  92760K  28740K  fg u0_a940  /system/b2g/b2g
   98  0   0% R     1      0K      0K     root     ksmd
    1  0   0% S     1    768K    448K     root     /init
    3  0   0% S     1      0K      0K     root     ksoftirqd/0
  910  0   0% S     1      0K      0K     root     RX_Thread
  991  0   0% S     6   7288K    608K     root     /system/bin/mpdecision
   19  1   0% S     1      0K      0K     root     smd_channel_clo
   20  1   0% S     1      0K      0K     root     smsm_cb_wq
   22  1   0% S     1      0K      0K     root     rpm-smd
   23  1   0% S     1      0K      0K     root     kworker/u:1H
   24  1   0% S     1      0K      0K     root     mpm
   25  0   0% S     1      0K      0K     root     irq/47-cpr
   61  0   0% S     1      0K      0K     root     sync_supers
   62  1   0% S     1      0K      0K     root     bdi-default

Comment 5

[Ben Francis [:benfrancis]]

(The device was noticeably hot, which prompted me to check top)

Comment 6

[Ben Francis [:benfrancis]]

I tried turning mobile data off and it doesn't seem to make any difference. Between 8am and 10am this morning the battery indicator went from full to half full with what I would call normal use (mainly just web browsing).

Again, /system/bin/sh seems to be using 50% CPU whilst displaying the homescreen:

User 67%, System 0%, IOW 0%, IRQ 0%
User 411 + Nice 0 + Sys 5 + Idle 191 + IOW 0 + IRQ 0 + SIRQ 0 = 607

  PID PR CPU% S  #THR     VSS     RSS PCY UID      Name
  275  1  50% R     1    936K    408K     shell    /system/bin/sh
 6727  1  16% R    20 186756K 112212K  bg u0_a6727 /system/b2g/b2g
 5499  0   1% S    20 265672K 193168K  bg u0_a5499 /system/b2g/b2g
 4923  0   1% R     1   1316K    532K     root     top
   98  0   0% S     1      0K      0K     root     ksmd
    8  0   0% S     1      0K      0K     root     migration/0
   13  1   0% S     1      0K      0K     root     khelper
   14  1   0% S     1      0K      0K     root     netns
   18  1   0% S     1      0K      0K     root     modem_notifier
   19  1   0% S     1      0K      0K     root     smd_channel_clo
   20  1   0% S     1      0K      0K     root     smsm_cb_wq
   22  1   0% S     1      0K      0K     root     rpm-smd
   23  0   0% S     1      0K      0K     root     kworker/u:1H
   24  1   0% S     1      0K      0K     root     mpm
   25  0   0% S     1      0K      0K     root     irq/47-cpr
   61  1   0% S     1      0K      0K     root     sync_supers

I checked the task manager and it showed the following windows open:

Privacy Controls (though I don't remember opening this)
Clock
7x browser windows
SMS
Email
Facebook
Marketplace
Twitter
Gallery
Settings

Comment 7

[Dale Harvey (:daleharvey)]

Privacy Controls keeps opening and not closing itself (similiar to how calendar used to), it should fix that, but more importantly I should be able to delete it, filed a bug for that

https://bugzilla.mozilla.org/show_bug.cgi?id=1031961

I have similiar issues with my phone being fairly hot coming out of my pocket and the battery dying fairly quickly

Comment 8

[Gregor Wagner [:gwagner]]

Jon, can you help out here? Do you see any recent spikes in power consumption?

Comment 9

[Jon Hylands [:jhylands]]

Gregor, I haven't been checking lately (been working on tool stuff).

Looking at the above, it seems pretty clear that this:

275  1  50% R     1    936K    408K     shell    /system/bin/sh

is a likely candidate - if one core of the CPU is red-lined, that will certainly chew battery. I've flashed my Flame to 188/latest 2.2, and I'll see if I can see it on the power profile.

Comment 10

[Jon Hylands [:jhylands]]

Attachment: Flame Browsing - Power Usage Graph

This is a snapshot of the power usage with 188/latest 2.2 user build flashed on my flame, connected to wifi (no SIM card), and browsing the web. When I hit the power button to put it to sleep, it drops almost instantly to ~15mA for about 30 seconds, and then down to ~1.5mA after that, which looks perfectly normal to me.

Comment 11

[Stephany Wilkes]

Blocking on this in advance of triage today, trying to get a jump on things. Gregor, can you help me find the correct component to which to assign this? Bit buried with CNY and FL on Monday and not sure about this one. Thanks!

Comment 12

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

bug 1003912 : Browser will chew up battery life on some websites.

Comment 13

[howie [:howie]]

qawanted for check the behavior on base image 18D

Comment 14

[Jayme Mercado [:JMercado] (Inactive 3/4/2016)]

I did not reproduce this issue with what I believe to be more than normal use of the phone for 7.5 hours today on the latest Nightly 3.0 build.  I spent 20-30 minutes per hour browsing the web, watching videos (in both the video app and on youtube), checking email, receiving calendar notifications, sending sms, and one call.  I did not use wifi, only data.  I believe this constitutes more usage than expected by an average user on an average day.

The phone was at 99% battery when this test was started and was at 54% at the end of the test.  Although I did not have a full 12 hours, the battery would have easily been usable for 16 hours at this rate.  

Another tester did testing on the latest Nightly 2.2 build and will comment with his results shortly.

Environmental Variables:
Device: Flame 3.0 KK (Full Flash) (319 MB)
BuildID: 20150306010207
Gaia: 7a91c16bfa348be8b25e09719178efa051512988
Gecko: 0189941a3fd5
Gonk: e7c90613521145db090dd24147afd5ceb5703190
Version: 39.0a1 (3.0) 
Firmware Version: v18D-1
User Agent: Mozilla/5.0 (Mobile; rv:39.0) Gecko/39.0 Firefox/39.0

Environmental Variables:
Device: Flame 2.2 KK (Full Flash) (319 MB)
BuildID: 20150306002519
Gaia: eb86137e247224e86d17ed1a0a133b2a318dce3c
Gecko: a04034e239fb
Gonk: e7c90613521145db090dd24147afd5ceb5703190
Version: 37.0 (2.2) 
Firmware Version: v18D-1
User Agent: Mozilla/5.0 (Mobile; rv:37.0) Gecko/37.0 Firefox/37.0

Comment 15

[Brogan Zumwalt [Inactive]]

Could not reproduce issue on Flame 2.2

With two email accounts syncing every 15 minutes, an hourly calendar event, and a clock alarm going off every hour (then being set to snooze), the device battery was, at the end of 8 hours still at 88% (after starting at 100% charged.)

The environmental variables for the Flame 2.2 device tested are posted above in comment 14

Comment 16

[Gabriele Svelto [:gsvelto] (PTO)]

I've encountered this sporadically in the past; it seemed to happen when I switched between the data connection and the WiFi one. I don't have a reproducible STR though and I actually haven't seen it in a couple of weeks at least. This is using master on a Flame for day-to-day dogfooding.

Comment 17

[Ken Chang[:kenkai]]

What was the base image you used when you encountered this problem?

Comment 18

[Kai-Chih Hu [:khu]]

Based on comment 15 and comment 16, it doesn't look like a 2.2 blocker now.

Comment 19

[Gabriele Svelto [:gsvelto] (PTO)]

I'm not 100% sure since it last happened some time ago but I think it was v18D.

Comment 20

[bhavana bajaj [:bajaj]]

CC'ing walter chen from MTBF team as he was tracking some battery related bugs and is talking to T2M related to issues.

there's nothing concrete here to go block 2.2 on , so removing the nom.

Comment 21

[nalah]

i have exactly the same bug :
my flame have 3 hours of life since the install of V18D, before more than 1 day ...
the phone is hot all the time.
I have to turn off the data to keep battery life.
Before I had no worries.

Comment 22

[Mark Trompell]

I experienced that issue first when updating to v18D_nigthly_v2 it was okay with v18D_nightly but iirc I had it with v188 too
not sure about that.
I can't see anything suspicious with top when connected with adb shell. Maybe everything is behaving when usb is connected.

Platform-Version: 41.0a1
Build-ID: 20150615010203
Update Channel: nightly
Commit: 2015-06-13 00:22.05
1bf2da10
Buildnumber: eng.cltbld.20150212.043653

Comment 23

[Gabriele Svelto [:gsvelto] (PTO)]

(In reply to Mark Trompell from comment #22)
> I can't see anything suspicious with top when connected with adb shell.

Please try using my tracing script as described in bug 1021400 comment 82. Note that tracing keeps working even when the phone is disconnected from the computer so that ADB doesn't influence the measurement (but keep in mind that re-plugging the phone turns the screen on which will affect the measure).

In my testing I've noticed two things: the system app seems to be waking up frequently when the phone in standby, this might be the culprit. When the browser app is open on a self-refresh page it seems to try and self-refresh even when it's in the background, this is less common though.

Comment 24

[April Morone]

(In reply to Mark Trompell from comment #22)
> I experienced that issue first when updating to v18D_nigthly_v2 it was okay
> with v18D_nightly but iirc I had it with v188 too
> not sure about that.
> I can't see anything suspicious with top when connected with adb shell.
> Maybe everything is behaving when usb is connected.
> 
> Platform-Version: 41.0a1
> Build-ID: 20150615010203
> Update Channel: nightly
> Commit: 2015-06-13 00:22.05
> 1bf2da10
> Buildnumber: eng.cltbld.20150212.043653

I use my LG Optimus Fuel phone's charger that can be plugged into the computer or the electrical socket.  It does this during either time, as well as does this when I don't have it plugged in, as well, whether on or off of battery power drain.  So that might not be the issue.

Comment 25

[April Morone]

(In reply to Mark Trompell from comment #22)
> I experienced that issue first when updating to v18D_nigthly_v2 it was okay
> with v18D_nightly but iirc I had it with v188 too
> not sure about that.
> I can't see anything suspicious with top when connected with adb shell.
> Maybe everything is behaving when usb is connected.
> 
> Platform-Version: 41.0a1
> Build-ID: 20150615010203
> Update Channel: nightly
> Commit: 2015-06-13 00:22.05
> 1bf2da10
> Buildnumber: eng.cltbld.20150212.043653

Sometimes, I have it plugged in just to charge, and when that is, I sometimes use my Android phone's charger that plugs into the wall, but that can plug into the computer, too, and I plug it into the wall electrical outlet to charge.  Other times, I use the USB cord to the computer that came with my Flame phone.  And still this occurs.  I also noticed that even when at full battery, after then unplugging it and turning it off right away, battery power still goes down, and shows as being at 84% battery power level right after turning the Flame phone back on (immediately after turning the phone back on, again).

Comment 26

[Gabriele Svelto [:gsvelto] (PTO)]

I've managed to reproduce this consistently and I've started a bisection. First of all this looks like a gecko issue, I've tried gaia checkouts as old as one month ago and they don't seem to have any effect on this. On gecko though I did the following testing:

- With the latest gaia...
- Build a version of gecko & flash it
- Wait for the phone to reboot then make sure the screen is off
- Wait 5 minutes
- Start kernel tracing, wait 5 minutes, stop it
- If there's a significant amount of wakeups for the main process (100+) then it's a bad version, otherwise it's a good one

I've semi-automated this step with the following command in the B2G clone:

./build.sh ; \
./flash.sh gecko ; \
sleep 600 ; \
./scripts/trace.sh --start ; \
sleep 300 ; \
./scripts.trace.sh --stop

Check the results, rinse and repeat. I've started my first bisection with gecko@4be5adc1749a it's a slow process though so it might take the better part of tomorrow to pinpoint the issue.

Comment 27

[April Morone]

(In reply to Gabriele Svelto [:gsvelto] from comment #26)
> I've managed to reproduce this consistently and I've started a bisection.
> First of all this looks like a gecko issue, I've tried gaia checkouts as old
> as one month ago and they don't seem to have any effect on this. On gecko
> though I did the following testing:
> 
> - With the latest gaia...
> - Build a version of gecko & flash it
> - Wait for the phone to reboot then make sure the screen is off
> - Wait 5 minutes
> - Start kernel tracing, wait 5 minutes, stop it
> - If there's a significant amount of wakeups for the main process (100+)
> then it's a bad version, otherwise it's a good one
> 
> I've semi-automated this step with the following command in the B2G clone:
> 
> ./build.sh ; \
> ./flash.sh gecko ; \
> sleep 600 ; \
> ./scripts/trace.sh --start ; \
> sleep 300 ; \
> ./scripts.trace.sh --stop
> 
> Check the results, rinse and repeat. I've started my first bisection with
> gecko@4be5adc1749a it's a slow process though so it might take the better
> part of tomorrow to pinpoint the issue.

Awesome.  Ty for doing this.  Please let me know how this goes.  :)

Comment 28

[Gabriele Svelto [:gsvelto] (PTO)]

Quick update, I'm also looking at bug 1173140 which is Aries-specific but I've seen the same behavior on the Flame so it's probably a generic problem in our codebase.

Comment 29

[Gabriele Svelto [:gsvelto] (PTO)]

The fix for bug 1180533 just landed on master, once it trickles down to tour flames please check if battery life has improved and report your findings here, we might be close to closing this (no pun intended).

Comment 30

[Gabriele Svelto [:gsvelto] (PTO)]

Another quick update. I'm not experiencing this stuff anymore except when going to a certain news page. After some inspection it turns out that the said publication has JavaScript code that self-refreshes the page instead of using an http-equiv=”refresh” meta tag. Considering that's the page misbehaving and there's nothing we can do about that on our side I'd consider this bug fixed as I haven't encountered the issue at hand anymore.

Comment 31

[Gabriele Svelto [:gsvelto] (PTO)]

Another update, yesterday I must have been lucky or something because today the issue is back. I've noticed it only with the data connection turned on. A quick check using the tracing script revealed a few interesting tidbits:

- There's a timer firing every 250ms and waking up the system app. I'm not sure where it's coming from yet so I need to investigate further.

- I see some storage-related activitiy, wakeups of a thread called 'file-storage' which seems to have been spawned by the system (i.e. outside of gecko), the IndexedDB worker thread also shows up.

- There's work being done by a DOM Worker thread, it wakes up every 5 seconds. I'm not sure if it's related to the storage activity I'm seeing but it might because there seem to be 5-6s intervals between the IndexedDB thread wakeups.

Comment 32

[Gabriele Svelto [:gsvelto] (PTO)]

I did a few more tests and I've got this additional data-points:

- The every-250ms timer wakeup and every-5s DOM Worker wakeup happen even when the network is disconnected (I had always tested with the data connection on until this point)

- On a freshly flashed flame without a SIM card and without my profile loaded I see the same behavior except for the IndexedDB activity. This might be related to the fact that I've used my dogfooding phone for testing and on a freshly flashed phone with an empty profile there's nothing to write to disk or something like that. But for the rest both timers tick at exactly the same time and they cause the same events.

Comment 33

[April Morone]

(In reply to Gabriele Svelto [:gsvelto] from comment #32)
> I did a few more tests and I've got this additional data-points:
> 
> - The every-250ms timer wakeup and every-5s DOM Worker wakeup happen even
> when the network is disconnected (I had always tested with the data
> connection on until this point)
> 
> - On a freshly flashed flame without a SIM card and without my profile
> loaded I see the same behavior except for the IndexedDB activity. This might
> be related to the fact that I've used my dogfooding phone for testing and on
> a freshly flashed phone with an empty profile there's nothing to write to
> disk or something like that. But for the rest both timers tick at exactly
> the same time and they cause the same events.

K.  Mine still does this with it for some reason.  I have second Flame reference phone with only 1.3 on it, and it is doing better of battery, though only just, anymore.  Not sure why that is. Could it be as simple as maybe just having a lot of extra apps on it that could be draining te battery?

Comment 34

[Gabriele Svelto [:gsvelto] (PTO)]

(In reply to April Morone from comment #33)
> K.  Mine still does this with it for some reason.  I have second Flame
> reference phone with only 1.3 on it, and it is doing better of battery,
> though only just, anymore.  Not sure why that is. Could it be as simple as
> maybe just having a lot of extra apps on it that could be draining te
> battery?

I haven't updated the bug because at some point my Flame became well behaved - somehow. Without the data connection battery life is very good, that's with my full, three years old profile and a bunch of applications. Turning on the data connection reduces battery life significantly but I don't see the fast drain I was experiencing in the past. This is on nightly BTW.

Comment 35

[April Morone]

(In reply to Gabriele Svelto [:gsvelto] from comment #34)
> (In reply to April Morone from comment #33)
> > K.  Mine still does this with it for some reason.  I have second Flame
> > reference phone with only 1.3 on it, and it is doing better of battery,
> > though only just, anymore.  Not sure why that is. Could it be as simple as
> > maybe just having a lot of extra apps on it that could be draining te
> > battery?
> 
> I haven't updated the bug because at some point my Flame became well behaved
> - somehow. Without the data connection battery life is very good, that's
> with my full, three years old profile and a bunch of applications. Turning
> on the data connection reduces battery life significantly but I don't see
> the fast drain I was experiencing in the past. This is on nightly BTW.

Ah. K. :) I noticed that, as well, of having it connected making the battery power level drain more quickly.  However, it still has done it somewhat quickly even when it was not connected.

Comment 36

[Gabriele Svelto [:gsvelto] (PTO)]

I haven't encountered this bug in the past two weeks and I've extensively used my Flame using nightly builds so I'm closing as WFM. If we hit this issue again let's open another bug.