864516 - CPU load spike at each minute mark of system time

Status: VERIFIED FIXED

(Firefox OS Graveyard :: Gaia::System, defect)

Description

[Diego Wilson [:diego]]

To reproduce:

1. Set display setting to "always on"
2. Open Gallery
3. Monitor CPU usage with |adb shell top | grep User|
4. In another terminal monitor system time with |while :; do adb shell date; sleep 1; done|

You'll see the spike every time the seconds hit :00

I don't see screen updates, so it doesn't seem to be related to rendering.

Comment 1

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

b2g is calling BuildDisplayList every 1 sec. And even if we hide homescreen (We launched gallery so homescreen is not in display), still we see paint event comes from B2G process. This paint causes cpu spike every 60 sec.

Comment 2

[Gabriele Svelto [:gsvelto]]

I think this might be caused by the Homescreen app. It installs a timer that refreshes the UI every 60s to repaint the date, see the code here:

https://github.com/mozilla-b2g/gaia/blob/master/apps/homescreen/js/landing.js#L42

I'll try to confirm this and if that's what's causing the spike I'll deploy a fix; should be a quick thing.

Comment 3

[Diego Wilson [:diego]]

@Tapas That's a good lead, thanks!

@gsvelto I can test any patch quickly if that helps

Comment 4

[Gabriele Svelto [:gsvelto]]

Confirmed, it's the homescreen updating the date every minute. Since the timer is never cleared when the homescreen is hidden it keeps running even with the screen turned off. I've got a patch underway and will post it shortly.

Comment 5

[Gabriele Svelto [:gsvelto]]

Attachment: Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9386

Pointer to Github pull-request

Comment 6

[Gabriele Svelto [:gsvelto]]

Comment on attachment 741405 [details]
Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9386

This patch disables the timers responsible for updating the clock/date on the homescreen whenever it becomes invisible including when the homescreen is turned off. The patch also ensures that the timers are properly cleared and do not accidentally pile up.

Comment 7

[Gabriele Svelto [:gsvelto]]

I'm asking for tef+ because I think it's worth back-porting this to 1.0.1. The patch is small and applies cleanly to v1-train and the bug it fixes is actually quite important for three reasons:

- This is making us drain the battery when the phone is idle with the screen turned off which is precisely when we should be consuming as little battery as possible.

- I think that we might actually be leaking a timer under certain conditions; I still have to verify it though.

- Since the timer ticks and refreshes the screen every minute this can also cause a slow-down of whatever application is running in the foreground when it happens. This might explain at least a part of the glitches / jitters we experience from time to time and which we couldn't figure out.

Comment 8

[Diego Wilson [:diego]]

Pasting my pull request comment in case it was missed:

> I still see a cpu spike in full screen apps (gallery). Is the event flow different in that case?

Comment 9

[Gabriele Svelto [:gsvelto]]

(In reply to Diego Wilson [:diego] from comment #8)
> Pasting my pull request comment in case it was missed:

I had missed it, sorry, I'll double-check but it should not be happening. If it is then the patch is not complete because we need to address both problems.

Comment 10

[Gabriele Svelto [:gsvelto]]

I've found out what's the problem is but first of all I'd like to thank Diego for spotting this out because it's a huge drag on battery life and it can negatively affect performance too.

Now on to the bug; the lockscreen is also updating it's time and it's doing so in a way that it will always run, no matter if it's shown or not, if the screen is turned on or off. To make matter worse it's doing it in a way that will trigger refreshing the date multiple times every time a second turns. Now that I've seen this in action I can see why the CPU spike was visible.

The offending code is here:

https://github.com/mozilla-b2g/gaia/blob/master/apps/system/js/lockscreen.js#L763

I'll submit a patch tomorrow; this needs to be fixed ASAP.

Comment 11

[Diego Wilson [:diego]]

Hmm... this seems like a regression. See bug 814076

Comment 12

[Gabriele Svelto [:gsvelto]]

Comment on attachment 741405 [details]
Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9386

Obsoleting this because I've got a complete patch ready that solves both the homescreen and lockscreen issues. I will post two separate pull requests, one for master and one backported for v1-train.

Comment 13

[Gabriele Svelto [:gsvelto]]

Attachment: Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9432

Pointer to Github pull-request

Comment 14

[Gabriele Svelto [:gsvelto]]

Comment on attachment 742424 [details]
Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9432

This is the pull-request for gaia/master: it prevents the homescreen and lockscreen clock refresh timers from ticking while they are invisible or the screen is off; it also prevents the timers from leaking.

Comment 15

[Gabriele Svelto [:gsvelto]]

Attachment: Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9433

Pointer to Github pull-request

Comment 16

[Gabriele Svelto [:gsvelto]]

Comment on attachment 742433 [details]
Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9433

This is the pull-request for gaia/v1-train.

Comment 17

[Diego Wilson [:diego]]

(In reply to Gabriele Svelto [:gsvelto] from comment #16)
> Comment on attachment 742433 [details]
> Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9433
> 
> This is the pull-request for gaia/v1-train.

In v1-train (not sure about master) another timer is used:

https://github.com/mozilla-b2g/gaia/blob/v1-train/apps/system/js/statusbar.js#L385

Once I remove it the spike goes away \o/

Comment 18

[Gabriele Svelto [:gsvelto]]

(In reply to Diego Wilson [:diego] from comment #17)
> In v1-train (not sure about master) another timer is used:
> 
> https://github.com/mozilla-b2g/gaia/blob/v1-train/apps/system/js/statusbar.
> js#L385

Argh! We're sourrounded by timers!

> Once I remove it the spike goes away \o/

Time to refresh the patches once more :-/ Thanks for spotting it, I think we might want to grep through Gaia to see if we're having more timer-related problems.

Comment 19

[Gabriele Svelto [:gsvelto]]

Attachment: Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9439

Pointer to Github pull-request

Comment 20

[Gabriele Svelto [:gsvelto]]

Comment on attachment 742713 [details]
Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9439

Refreshed pull-request for v1-train

Comment 21

[Gabriele Svelto [:gsvelto]]

OK, I've refreshed both pull requests and I had to re-do the v1-train one due to me messing up with my remote branch. To sum up the changes I made:

- Made the homescreen, lockscreen and status-bar stop refreshing their time displays when the screen is off or they are invisible, this prevents the CPU spike seen in this bug

- Fixed timer-leaks caused by starting the same timer twice overwriting the previous one without cancelling it

- Made the statusbar clock reflect locale changes immediately

Comment 22

[Diego Wilson [:diego]]

The latest v1-train patch did it for me :)

You know what's even cooler? Now there's not even a spike while viewing the homescreen clock! Good job Gabriele!

Comment 23

[Yuren [:yurenju] (AFK ~ Oct. 12) (volunteer mode)]

Comment on attachment 742713 [details]
Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9439

left comment on github. set review? to me again when you updated.

Comment 24

[Cristian Rodriguez (:crdlc)]

Comment on attachment 742424 [details]
Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9432

My review is positive only for homescreen where I can review. I could say that the rest is ok but I don't have a strong knowledge in these parts of Gaia.

Comment 25

[Gabriele Svelto [:gsvelto]]

(In reply to Yuren Ju [:yurenju] from comment #23)
> left comment on github. set review? to me again when you updated.

Thank you for the review; I'll extract the clock object and factorize the related code.

(In reply to Cristian Rodriguez (a remontar!) from comment #24)
> My review is positive only for homescreen where I can review. I could say
> that the rest is ok but I don't have a strong knowledge in these parts of
> Gaia.

Thank you for your review; I'll ask for Yuren review for the statusbar/lockscreen.

Comment 26

[Alex Keybl [:akeybl]]

Any updates here? Sounds like we're really close, why is this dragging?

Comment 27

[(inactive after 6/18) Alive Kuo [:alive]]

Comment on attachment 742713 [details]
Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9439

I think Yuren had given a r- per comment 23 (by canceling the review flag). See github comments.

Comment 28

[Gabriele Svelto [:gsvelto]]

(In reply to Alex Keybl [:akeybl] from comment #26)
> Any updates here? Sounds like we're really close, why is this dragging?

I'm on PTO until next week but but I'll probably post a revised patch tomorrow anyway :)

Comment 29

[Gabriele Svelto [:gsvelto]]

Comment on attachment 742713 [details]
Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9439

Refreshed patch addressing the comments on GitHub; I will ask for review for the master version too as they have some non-trivial differences.

Comment 30

[Gabriele Svelto [:gsvelto]]

Comment on attachment 742424 [details]
Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9432

Same as above; the Travis build doesn't show lint issues but fails to run because of something that seems unrelated to my changes.

Comment 31

[Yuren [:yurenju] (AFK ~ Oct. 12) (volunteer mode)]

Comment on attachment 742424 [details]
Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9432

looks good, thank you :)

Comment 32

[Gabriele Svelto [:gsvelto]]

Thanks Yuren!

Merged on master and v1-train:

https://github.com/mozilla-b2g/gaia/commit/64fc300e8e03b1718e91ca65d42f53f0d83b69e4
https://github.com/mozilla-b2g/gaia/commit/4619a4da0776d1753e58f1564d60643da5020425

Comment 33

[John Ford [:jhford] CET/CEST Berlin Time]

(In reply to Gabriele Svelto [:gsvelto] from comment #32)
> Thanks Yuren!
> 
> Merged on master and v1-train:
> 
> https://github.com/mozilla-b2g/gaia/commit/
> 64fc300e8e03b1718e91ca65d42f53f0d83b69e4
> https://github.com/mozilla-b2g/gaia/commit/
> 4619a4da0776d1753e58f1564d60643da5020425

Thanks for landing this on branches!  It's really helpful if you set the branch status flags when landing on branches.  I've fixed the flag for status-b2g18, but this still isn't fixed on v1.0.1.  There is a conflict when I try to cherry-pick this change to v1.0.1.

Comment 34

[Gabriele Svelto [:gsvelto]]

Attachment: Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9593

Pointer to Github pull-request

Comment 35

[Gabriele Svelto [:gsvelto]]

Comment on attachment 746420 [details]
Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/9593

Here's the pull-request for v1.0.1, merge at will :-) Sorry for not setting the flags correctly.

Comment 36

[Gabriele Svelto [:gsvelto]]

I went ahead and merged on v1.0.1; I had to do only a few small changes for getting it to work and I've tested it on my Unagi where it seems to work as expected.

Comment 37

[Deepa Subramanian]

I do not see a spike every time the seconds hit :00. Saw 1-2% increase only.

Issue seems to be fixed. Verified on

Inari Build ID: 20130515070203
Gecko  http://hg.mozilla.org/releases/mozilla-b2g18_v1_0_1/rev/0b6bcb1f4175
Gaia   9648799c2e45917ff150fa9eef8aeac79a9ac008

Leo Build ID: 20130513230207 
Gecko  http://hg.mozilla.org/releases/mozilla-b2g18/rev/606c4fa198c2
Gaia   23cec618ba1ad9f39da1fc5dfa2a4df2b2d5f933