1188643 - [Aries][Flame][Ringtones] Previewing a custom ringtone sounds choppy

Status: RESOLVED FIXED

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

Description

[Oliver Nelson [:oliverthor]]

Attachment: logcat_20150728_1504.txt

Description:
When a user adds a custom ringtone (from their music app) to their Aries device, they will observe that previewing the song within 'Manage Tones' alongside the default tones will play choppy/staticy. When setting up the ringtone via share activity, or receiving a phone call with the ringtone default, the track will play fine as expected.

PreReq:
* music on device
Repro Steps:
1) Update a Flame to 20150728030208
2) Open Settings app
3) Tap 'Sounds'
4) Tap 'Manage Tones'
5) Tap '+' in top right
6) Proceed through share activity and save the ringtone
7) Tap the ringtone to preview

Actual:
Ringtone preview sounds choppy

Expected:
Ringtone preview is clear/identical to track in music.


Environmental Variables:
------------------------------

Device: Aries 2.5
BuildID: 20150727151800
Gaia: 4e3e21a4ba3f188b45623ee2297f21d0791f8667
Gecko: 21ca97268bae
Gonk: 2916e2368074b5383c80bf5a0fba3fc83ba310bd
Version: 42.0a1 (2.5) 
Firmware Version: D5803_23.1.A.1.28_NCB.ftf
User Agent: Mozilla/5.0 (Mobile; rv:42.0) Gecko/42.0 Firefox/42.0


Master build on flame can't follow STR due to bug 1188603
Sharing from music instead can add song successfully.
Results: Ringtone preview sounds choppy

Device: Flame 2.5
Build ID: 20150728030208
Gaia: 14e32276025b0310d3e89027320cf4b2a24cedfb
Gecko: 33dc8a83cfc0
Gonk: 41d3e221039d1c4486fc13ff26793a7a39226423
Version: 42.0a1 (2.5)
Firmware Version: v18D
User Agent: Mozilla/5.0 (Mobile; rv:42.0) Gecko/42.0 Firefox/42.0
============================

Issue then DOES NOT REPRODUCE on 2.2 for flame devices
Results: Ringtone preview is clear/identical to track in music.

Device: Flame 2.2
BuildID: 20150728032504
Gaia: e1e6317f17a840b19af9dbb25f5a771d8d9fa161
Gecko: 9b60e57724db
Gonk: bd9cb3af2a0354577a6903917bc826489050b40d
Version: 37.0 (2.2) 
Firmware Version: v18D
User Agent: Mozilla/5.0 (Mobile; rv:37.0) Gecko/37.0 Firefox/37.0
------------------------------

Repro frequency: 5/5
See attached: 
video- https://youtu.be/Epj5CJxE8TI
logcat

Comment 1

[Peter Bylenga [:PBylenga]]

[Blocking Requested - why for this release]:
Audio performance regression.

Requesting a window, perhaps increasing memory on flame will unblock from bug 1188603

Comment 2

[Hema Koka [:hema]]

Regression, blocking

Comment 3

[Duane Dixon [:ddixon]]

Central Regression Window

Last Working

Device: Flame 2.5
BuildID: 20150617090748
Gaia: 29e990805540fa4d1d03f1144bf9c95364ef6b51
Gecko: 06339ff6a374
Version: 41.0a1 (2.5)
Firmware Version: v18D-1
User Agent: Mozilla/5.0 (Mobile; rv:41.0) Gecko/41.0 Firefox/41.0

First Broken

Device: Flame 2.5
BuildID: 20150617115748
Gaia: 29e990805540fa4d1d03f1144bf9c95364ef6b51
Gecko: 099d6cd6725e
Version: 41.0a1 (2.5)
Firmware Version: v18D-1
User Agent: Mozilla/5.0 (Mobile; rv:41.0) Gecko/41.0 Firefox/41.0

Last Working Gaia and First Broken Gecko
Issue DOES occur here (constant distortion)
Gaia: 29e990805540fa4d1d03f1144bf9c95364ef6b51
Gecko: 099d6cd6725e

Last Working Gecko and First Broken Gaia
Issue DOES NOT occur here
Gaia: 29e990805540fa4d1d03f1144bf9c95364ef6b51
Gecko: 06339ff6a374

Gecko Pushlog:
http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=06339ff6a374&tochange=099d6cd6725e

Mozilla Inbound Regression Window

Last Working

Device: Flame 2.5
BuildID: 20150616125649
Gaia: 9d42e94446f2dc01b519172b6d75d81d4d435bdc
Gecko: f049fcbdfe1e
Version: 41.0a1 (2.5)
Firmware Version: v18D-1
User Agent: Mozilla/5.0 (Mobile; rv:41.0) Gecko/41.0 Firefox/41.0

First Broken

Device: Flame 2.5
BuildID: 20150616130050
Gaia: 9d42e94446f2dc01b519172b6d75d81d4d435bdc
Gecko: c1b33c43f0c5
Version: 41.0a1 (2.5)
Firmware Version: v18D-1
User Agent: Mozilla/5.0 (Mobile; rv:41.0) Gecko/41.0 Firefox/41.0


Last Working Gaia and First Broken Gecko
Issue DOES occur here
Gaia: 9d42e94446f2dc01b519172b6d75d81d4d435bdc
Gecko: c1b33c43f0c5

Last Working Gecko and First Broken Gaia
Issue DOES NOT occur here
Gaia: 9d42e94446f2dc01b519172b6d75d81d4d435bdc
Gecko: f049fcbdfe1e

Gecko Pushog:
hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=f049fcbdfe1e&tochange=c1b33c43f0c5


Possible Cause:

Bug 1163223 - Clean up MDSM start time handling

Comment 4

[KTucker [:KTucker][Inactive 3/4/2016]]

Bobby, can you take a look at this please? This might have been caused by the work done for bug 1163223.

Comment 5

[Jean-Yves Avenard [:jya]]

Is it on Flame or Aries ?

I'm confused

Comment 6

[KTucker [:KTucker][Inactive 3/4/2016]]

It is happening on both Aries and on Flame with 512mb of memory.

Comment 7

[Jean-Yves Avenard [:jya]]

An Aries has been shipped to my address this week schedule to arrive mid next week. I'll have a look then. 

What audio format are the ringtones saved under?

Comment 8

[Jean-Yves Avenard [:jya]]

is there a way to use a custom ringtone without an SD card?

I need to get one otherwise.

Comment 9

[Bobby Holley (:bholley)]

Sotaro is very familiar with this stuff - maybe he could help out here?

Comment 10

[Jim Porter (:squib)]

This sounds really, really similar to bug 1166758. Marking blocker for now.

Comment 11

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

(In reply to Jim Porter (:squib) from comment #10)
> This sounds really, really similar to bug 1166758. Marking blocker for now.
Yeah. I will check it.

Comment 12

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

This problem can be seen on Flame as well.

Comment 13

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

This bug should be not similar to bug 1166758 since currently ring tone is playing via WebAudio which is different from bug 116678 (normal playback via audio tag).
 
JW, 
Per comment 3, it looks like Bug 1163223 could be the possible cause. 
Can you help check it?
Thanks!

Comment 14

[JW Wang [:jwwang] [:jw_wang]]

Hi Oliver,
Can you provide the files that sound choppy? I don't have nay music file in the SD card.

Comment 15

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

(In reply to JW Wang [:jwwang] from comment #14)
> Hi Oliver,
> Can you provide the files that sound choppy? I don't have nay music file in
> the SD card.
I can provide you.

Comment 16

[JW Wang [:jwwang] [:jw_wang]]

Got tons of below messages on flame:
I/PRLog   ( 7371): 2015-09-22 17:07:33.788976 UTC - -1192092152[afab3800]: Decoder=afe54020 Changed mNextFrameStatus to NEXT_FRAME_UNAVAILABLE                                                              [5/788]
I/PRLog   ( 7371): 2015-09-22 17:07:33.790336 UTC - -1192092152[afab3800]: Decoder=afe54020 Changed mNextFrameStatus to NEXT_FRAME_AVAILABLE
I/PRLog   ( 7371): 2015-09-22 17:07:33.952338 UTC - -1192091568[afdc7f00]: Decoder=afe54020 Changed mNextFrameStatus to NEXT_FRAME_UNAVAILABLE
I/PRLog   ( 7371): 2015-09-22 17:07:33.953108 UTC - -1192091568[afdc7f00]: Decoder=afe54020 Changed mNextFrameStatus to NEXT_FRAME_AVAILABLE
I/PRLog   ( 7371): 2015-09-22 17:07:34.034286 UTC - -1192091568[afdc7f00]: Decoder=afe54020 Changed mNextFrameStatus to NEXT_FRAME_UNAVAILABLE
I/PRLog   ( 7371): 2015-09-22 17:07:34.034793 UTC - -1192091568[afdc7f00]: Decoder=afe54020 Changed mNextFrameStatus to NEXT_FRAME_AVAILABLE
I/PRLog   ( 7371): 2015-09-22 17:07:34.156937 UTC - -1192093904[afab3f00]: Decoder=afe54020 Changed mNextFrameStatus to NEXT_FRAME_UNAVAILABLE
I/PRLog   ( 7371): 2015-09-22 17:07:34.158049 UTC - -1192093904[afab3f00]: Decoder=afe54020 Changed mNextFrameStatus to NEXT_FRAME_AVAILABLE
I/PRLog   ( 7371): 2015-09-22 17:07:34.198183 UTC - -1192092736[afdc7f80]: Decoder=afe54020 Changed mNextFrameStatus to NEXT_FRAME_UNAVAILABLE
I/PRLog   ( 7371): 2015-09-22 17:07:34.198940 UTC - -1192092736[afdc7f80]: Decoder=afe54020 Changed mNextFrameStatus to NEXT_FRAME_AVAILABLE

It looks like |NO_VIDEO_AMPLE_AUDIO_DIVISOR==8| is just too aggressive to prevent audio buffer underrun on flame. The glitch becomes much better after changing NO_VIDEO_AMPLE_AUDIO_DIVISOR to 4.

Comment 17

[JW Wang [:jwwang] [:jw_wang]]

Hi Chris,
Did your test (bug 984698 comment 1) include the capture-stream case?

I can play audio smoothly without glitch on flame with |NO_VIDEO_AMPLE_AUDIO_DIVISOR==8| when audio not captured. However, |NO_VIDEO_AMPLE_AUDIO_DIVISOR==8| seems too aggressive in the capture-stream case.

Comment 18

[Chris Pearce [:cpearce (Not reading bugmail)]]

I did not test the capture stream case. We could always special case it in the (HasAudio() && !HasVideo()) branch there.

Comment 19

[JW Wang [:jwwang] [:jw_wang]]

Attachment: 1188643_fix_buffering-v1.patch

Hi Duane,
Can you try if this patch fixes the glitches? Thanks.

Comment 20

[JW Wang [:jwwang] [:jw_wang]]

Attachment: MozReview Request: Bug 1188643. Buffer more audio in audio capture mode to avoid glitches. r=cpearce.

Bug 1188643. Buffer more audio in audio capture mode to avoid glitches.

Comment 21

[Chris Pearce [:cpearce (Not reading bugmail)]]

Comment on attachment 8665241 [details]
MozReview Request: Bug 1188643. Buffer more audio in audio capture mode to avoid glitches. r=cpearce.

https://reviewboard.mozilla.org/r/20185/#review18113

Comment 22

[JW Wang [:jwwang] [:jw_wang]]

Thanks for the review!

Comment 23

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/dcbabf6ce153

Comment 24

[JW Wang [:jwwang] [:jw_wang]]

https://reviewboard.mozilla.org/r/20185/#review18127

::: dom/media/MediaDecoderStateMachine.cpp:2077
(Diff revision 1)
> +  AssertCurrentThreadInMonitor();

Oops\! We should acquire the monitor instead of asserting it. Gonna fix and push it again.

Comment 25

[JW Wang [:jwwang] [:jw_wang]]

Try again: https://treeherder.mozilla.org/#/jobs?repo=try&revision=c6d364c6c847

Comment 26

[Pulsebot]

Backout:
https://hg.mozilla.org/integration/mozilla-inbound/rev/3e3620f7905d

Comment 27

[JW Wang [:jwwang] [:jw_wang]]

Ok, I found the problem.

The watcher listeners are executed in direct tasks instead of being called directly when a watchable changes. This changes the timing when AdjustAudioThresholds() is called.

We need to check audio prerolling again after changing audio thresholds. Otherwise, we will stuck in a place where playback is not started for audio prerolling is true, yet we don't decode new audio samples for decoded audio duration is larger than |mAmpleAudioThresholdUsecs|.

Try is green: https://treeherder.mozilla.org/#/jobs?repo=try&revision=1a6e60f95d3a

Comment 28

[JW Wang [:jwwang] [:jw_wang]]

Comment on attachment 8665241 [details]
MozReview Request: Bug 1188643. Buffer more audio in audio capture mode to avoid glitches. r=cpearce.

Bug 1188643. Buffer more audio in audio capture mode to avoid glitches. r=cpearce.

Comment 29

[JW Wang [:jwwang] [:jw_wang]]

Comment on attachment 8665241 [details]
MozReview Request: Bug 1188643. Buffer more audio in audio capture mode to avoid glitches. r=cpearce.

Fix the problem in comment 27.
Try: https://treeherder.mozilla.org/#/jobs?repo=try&revision=1a6e60f95d3a

Comment 30

[Chris Pearce [:cpearce (Not reading bugmail)]]

Comment on attachment 8665241 [details]
MozReview Request: Bug 1188643. Buffer more audio in audio capture mode to avoid glitches. r=cpearce.

https://reviewboard.mozilla.org/r/20185/#review18623

::: dom/media/MediaDecoderStateMachine.cpp:2081
(Diff revision 2)
> +  auto divisor = mAudioCaptured ? NO_VIDEO_AMPLE_AUDIO_DIVISOR / 2

I would prefer to only use 'auto' for really complex templated types, like iterators, rather than for plain types.

For example, just looking at this code, I can't tell if it's signed or 32/64 bit.

Comment 31

[JW Wang [:jwwang] [:jw_wang]]

https://reviewboard.mozilla.org/r/20185/#review18679

::: dom/media/MediaDecoderStateMachine.cpp:2081
(Diff revision 2)
> +  auto divisor = mAudioCaptured ? NO_VIDEO_AMPLE_AUDIO_DIVISOR / 2

Thanks for the review. In fact 'auto' guarantees the type of divisor is the same as NO_VIDEO_AMPLE_AUDIO_DIVISOR which is exactly our intention. I will use int64_t for readability.

Comment 32

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/09eb2d17aa32

Comment 33

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/09eb2d17aa32