1214208 - Power Consumption increased in music app while playing music

Status: RESOLVED FIXED

(Core :: Audio/Video: Playback, defect, P2)

Description

[Jon Hylands [:jhylands]]

The new music app is showing a fairly significant power regression while playing music, both with the screen on and with the screen off.

https://raptor.mozilla.org/dashboard/script/power?var-device=flame-kk&var-memory=1024&var-branch=master

Click on the top right button where it says "3 days ago..." and change that to last 30 days. As soon as the automated tests worked again (Oct 9) the power usage jumped, and has remained higher.

Comment 1

[Jon Hylands [:jhylands]]

Attachment: Raptor Screenshot with regression highlighted

Comment 2

[No-Jun Park [:njpark]]

[Blocking Requested - why for this release]:
It's a regression, and the percentage of additional power consumption is significant

Comment 3

[Jon Hylands [:jhylands]]

Attachment: Old Music Player - Manual Test

Here's a screenshot of the pwoer harness measuring playing a song (screen off) with a PVT build from Sept 25. This shows actual power consumed, without the overhead imposed by the USB charger being turned off in the automated test system.

Comment 4

[Jon Hylands [:jhylands]]

Attachment: New Music Player - Manual Test

Here's a screenshot of the power harness measuring playing the same song (screen off) with a PVT build from Oct 13.

Power consumption is noticeably higher here.

Comment 5

[Gregor Wagner [:gwagner]]

Jon, can you narrow it down the regression range to a day?

Comment 6

[Jon Hylands [:jhylands]]

I'm pretty sure that it was the day the new version of the app was released, but I will validate that...

Comment 7

[Jon Hylands [:jhylands]]

So, it turns out I was wrong.

The regression first appeared in this build:

https://pvtbuilds.mozilla.org/pvt/mozilla.org/b2gotoro/nightly/mozilla-central-flame-kk/2015/10/2015-10-02-15-02-29/

So something that was merged on Oct 2, between the first PVT build and the second one.

Comment 8

[Justin D'Arcangelo [:justindarc]]

(In reply to Jon Hylands [:jhylands] from comment #7)
> So, it turns out I was wrong.
> 
> The regression first appeared in this build:
> 
> https://pvtbuilds.mozilla.org/pvt/mozilla.org/b2gotoro/nightly/mozilla-
> central-flame-kk/2015/10/2015-10-02-15-02-29/
> 
> So something that was merged on Oct 2, between the first PVT build and the
> second one.

Jon: I looked at the gaia commits for the Music app around Oct. 2, and they mostly revolved around adding the `[defer]` attribute to our `<script>` tags. Nothing that deals with audio playback was changed. If you flash an ENG build from PVT, you will get both the old Music app and the new Music app installed together. I'm curious to see if there is any difference in power consumption for audio playback between the two. If both apps show the same power regression, then its likely that this is an issue with Gecko audio playback. I was going to try and run fxos-powertool yesterday, but didn't get around to it.

Comment 9

[Jon Hylands [:jhylands]]

Justin - it looks like its probably a gecko issue - both apps display the same power profile on the Oct 2 Eng build.

Comment 10

[Jon Hylands [:jhylands]]

Here's the gecko log for the two versions:

http://hg.mozilla.org/integration/b2g-inbound/pushloghtml?fromchange=5f16c6c2b969&tochange=0010c0cb259e

Comment 11

[Bobby Chien]

Per comment 8, not sure this could be easy investigated or not. Blake, do you have any comment on this?

Comment 12

[Blake Wu [:bwu][:blakewu]]

First of all, Thanks Jon. This is so cool! I didn't know we have this hardness to monitor power consumption. 
After quickly checking the long list of gecko committed logs from comment 10, I cannot find a suspicious one. 
Does anyone know will there be any quick way to find the patch caused this regression?

Comment 13

[Gregor Wagner [:gwagner]]

Bug 1209410 sticks out here but Jon will verify.

Comment 14

[Jon Hylands [:jhylands]]

I've verified that Bug 1209410 does not seem to be the problem, because I checked out the commit prior to that, and the problem is still there. I'll continue bisecting today...

Comment 15

[Blake Wu [:bwu][:blakewu]]

(In reply to Jon Hylands [:jhylands] from comment #14)
> I've verified that Bug 1209410 does not seem to be the problem, because I
> checked out the commit prior to that, and the problem is still there. I'll
> continue bisecting today...
A million thanks!

Comment 16

[Jon Hylands [:jhylands]]

Okay, so it turns out I was looking at the list backwards, and Bug 1209410 is in fact the culprit.

Comment 17

[Gregor Wagner [:gwagner]]

Jean, can we do anything here?

Comment 18

[Jean-Yves Avenard [:jya]]

I can't really see why enabling the MP3Demuxer would significantly increase power usage. How much higher is it ?

Can you run a profiler to see where most of the time is spent?

Bug 1209410 may also expose an issue with the Gonk PDM (the MP3 decoder) which wasn't called before (it was only called for decoding MP3 inside MP4 containers)

There's been some changes recently on the Gonk PDM to make it faster at decoding H264; could this has an affect on power usage?

Eugene is this something you could look into?

Comment 19

[Jon Hylands [:jhylands]]

Running manual power tests, the old music player took an average of 27 mA running with the screen off, and the new one takes 67 mA. That's a difference of 40 mA, and more than double the power used.

In real terms, its the difference between 55 hours of play time and 22 hours (assuming 1500 mAh available from the battery).

Comment 20

[Jon Hylands [:jhylands]]

Sorry, I misspoke in the last comment. Its not an issue of the old or new player. What I meant to say was, pre-regression power usage is 27 mA, and post-regression is 67 mA.

Comment 21

[Eugen Sawin [:esawin]]

That's a significant regression. I suspect that it's the decoder, since the new demuxer is modeled after the previous one with no significant semantic changes, but I wouldn't rule it out before seeing the profiling logs.

I don't have a FxOS setup, can you please run a profiler and report the results? I can see what profiling gives us on Android, but we don't have power usage metrics and it would be using MediaCodec's decoder.

Comment 22

[Blake Wu [:bwu][:blakewu]]

(In reply to Jean-Yves Avenard [:jya] from comment #18)
> I can't really see why enabling the MP3Demuxer would significantly increase
> power usage. How much higher is it ?
> 
> Can you run a profiler to see where most of the time is spent?
> 
> Bug 1209410 may also expose an issue with the Gonk PDM (the MP3 decoder)
> which wasn't called before (it was only called for decoding MP3 inside MP4
> containers)
> 
> There's been some changes recently on the Gonk PDM to make it faster at
> decoding H264; could this has an affect on power usage?
Probably. 
Alfredo, do you have any ideas which might affect this?

Comment 23

[Mahendra Potharaju [:mahe]]

Blocking for 2.5 based on how bad the battery consumption can get

Comment 24

[Sotaro Ikeda [:sotaro]]

Is there a possibility that is related to usage of AudioOffloadPlayer? Bug 1149984 might be related to it.

Comment 25

[Ken Chang[:kenkai]]

Alfredo, any update?

Comment 26

[Alfredo Yang (:alfredo)]

(In reply to Sotaro Ikeda [:sotaro] from comment #24)
> Is there a possibility that is related to usage of AudioOffloadPlayer? Bug
> 1149984 might be related to it.

I'm confused about it. Is AudioOffloadPlayer enable on PDM? Why do you think AudioOffloadPlayer is related to this bug?

Comment 27

[Sotaro Ikeda [:sotaro]]

(In reply to Alfredo Yang (:alfredo) from comment #26)
> (In reply to Sotaro Ikeda [:sotaro] from comment #24)
> > Is there a possibility that is related to usage of AudioOffloadPlayer? Bug
> > 1149984 might be related to it.
> 
> I'm confused about it. Is AudioOffloadPlayer enable on PDM? Why do you think
> AudioOffloadPlayer is related to this bug?

I just said that when MediaFormatReader is used for decoding, AudioOffloadPlayer is not used. It causes the power consumption up during music playback.

Comment 28

[Ken Chang[:kenkai]]

Is there anything we can do for this bug?

Comment 29

[Alfredo Yang (:alfredo)]

(In reply to Ken Chang[:ken] from comment #28)
> Is there anything we can do for this bug?

Bug 1209410 turns on mp3 decoding in Gonk PDM. I'm checking if the test audio matching this and any CPU spinning in test. I'll update it soon.

Comment 30

[Blake Wu [:bwu][:blakewu]]

Assign to Alfredo. 
Hi Alfredo, 
Please feel free to un-assign yourself if you are not the right person to check this bug.
Thanks!

Comment 31

[Eugen Sawin [:esawin]]

Can you please test patch 5 [1] from bug 1163667 to see whether decreasing the scan buffer size has an effect on power consumption?

[1] https://bug1163667.bmoattachments.org/attachment.cgi?id=8677642

Comment 32

[Jon Hylands [:jhylands]]

Applying that patch has no apparent effect on power consumption.

Comment 33

[Alfredo Yang (:alfredo)]

Ok, I think I got the whole picture.

AudioOffloadPlayer is an audio tunneling mode player on Gonk. It uses less CPU and power comparing to normal playback engine when playing audio only, non-streaming file.
 
Bug 1209410 switches mp3 decoder to PDM. Unfortunately, current Gonk PDM doesn't support AudioOffloadPlayer. And then this regression happens.

So it needs to switch back to AudioOffloadPlayer or supports AudioOffloadPlayer on gonk PDM.

Comment 34

[Jean-Yves Avenard [:jya]]

Attachment: Do not use MP3Decoder on B2G. r=alfredo

the Gonk PDM doesn't support AudioOffloadPlayer leading to increased power consumption.

Comment 35

[Jean-Yves Avenard [:jya]]

Comment on attachment 8677982 [details] [diff] [review]
Do not use MP3Decoder on B2G. r=alfredo

This disable the new MP3Decoder on platform with the OMX player.

Alfredo, I'm not sure if OMX is used on Android or not, and the MP3Decoder was primarily implemented for adding MP3 support to newer Android version.

Comment 36

[Jon Hylands [:jhylands]]

Comment on attachment 8677982 [details] [diff] [review]
Do not use MP3Decoder on B2G. r=alfredo

This patch fixes the power regression.

Comment 37

[Alfredo Yang (:alfredo)]

(In reply to Jean-Yves Avenard [:jya] from comment #35)
> Comment on attachment 8677982 [details] [diff] [review]
> Do not use MP3Decoder on B2G. r=alfredo
> 
> This disable the new MP3Decoder on platform with the OMX player.
> 
> Alfredo, I'm not sure if OMX is used on Android or not, and the MP3Decoder
> was primarily implemented for adding MP3 support to newer Android version.

I think Fennec doesn't use OMX (actually, it is stagefright) directly like Gonk.

Comment 38

[Sotaro Ikeda [:sotaro]]

Android uses java's Mediacodec(Bug 1014614, Bug 1097126) to avoid symbol mismatch problem on recent android. Android devices have modification to their native(c++ code) and it causes symbol mismatch if gecko uses c++ MediaCodec. And android applications do not have permission to load hw codec in their processes. Using java api makes them more stable than use c++ code.

Comment 39

[Jean-Yves Avenard [:jya]]

(In reply to Sotaro Ikeda [:sotaro] from comment #38)
> Android uses java's Mediacodec(Bug 1014614, Bug 1097126) to avoid symbol
> mismatch problem on recent android. Android devices have modification to
> their native(c++ code) and it causes symbol mismatch if gecko uses c++
> MediaCodec. And android applications do not have permission to load hw codec
> in their processes. Using java api makes them more stable than use c++ code.

I'm not sure the link with this bug, but what you describe maybe the reason why we have bug 1192539.

Just attempting to create the decoder causes a crash

Comment 40

[Jean-Yves Avenard [:jya]]

Comment on attachment 8677982 [details] [diff] [review]
Do not use MP3Decoder on B2G. r=alfredo

Review of attachment 8677982 [details] [diff] [review]:
-----------------------------------------------------------------

Well, if OMX is only used by B2G, that should be all that we need then.

Comment 41

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/34564c10054d

Comment 42

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/34564c10054d

Comment 43

[Jon Hylands [:jhylands]]

I can validate that the current build (from taskcluster) shows this regression as fixed.

https://raptor.mozilla.org/dashboard/script/power?var-device=flame-kk&var-memory=1024&var-branch=master&from=1442768969400&to=1446052303116