1242783 - amr file types will stutter when played through Bluetooth speakers or headphones

Status: RESOLVED FIXED

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

Description

[Adam Alldredge [:AdamA][Inactive]]

Attachment: logcat

Description:
If the user is listening to music through a bluetooth headphone or speaker and an amr file begins to play it will stutter. if the user plays the song on the phone alone it will not stutter but if they connect the bluetooth device and play the song then disconnect the bluetooth it will stutter in the phone.

Prerequisite:
Have an AMR file on the phone.

Repro Steps:
1) Update a Aries to 20160125140104
2) Connect a bluetooth headset/speakers
3) Open music
4) Play AMR file
5) Observe audio

Actual:
The audio stutters while the song is playing

Expected:
It is expected that the audio does not stutter when using bluetooth devices to listen to music.

Environmental Variables:
Device: Aries 2.6 [Full Flash]
Build ID: 20160125140104
Gaia: 4023297b16fdc46de3ddb04be4f3c575313d1cde
Gecko: 3f41d7d0f544ebd98273e39bd945c28878a47427
Gonk: a19052e4389c3ae2d8fc3e7a74a475401baacc56
Version: 46.0a1 (2.6)
Firmware Version: D5803_23.1.A.1.28_NCB.ftf
User Agent: Mozilla/5.0 (Mobile; rv:46.0) Gecko/46.0 Firefox/46.0

Repro frequency: 10/10
See attached: video clip, logcat. amr file

Comment 1

[Adam Alldredge [:AdamA][Inactive]]

This issue DOES occur on Flame 2.6.

Environmental Variables:
Device: FlameKK 2.6 [Full Flash][512mb]
BuildID: 20160125030234
Gaia: 4023297b16fdc46de3ddb04be4f3c575313d1cde
Gecko: 67c66c2878aed17ae3096d7db483ddbb2293c503
Gonk: 205ac4204bbbb2098a8046444acba551ba5dc75a
Version: 46.0a1 (2.6) 
Firmware Version: v18D v5
User Agent: Mozilla/5.0 (Mobile; rv:46.0) Gecko/46.0 Firefox/46.0

Result:
The audio stutters while the song is playing
-------------------------------------
This issue DOES NOT occur on Aries 2.5.

Environmental Variables:
Device: Aries 2.5 [Full Flash]
BuildID: 20160122183338
Gaia: 53ba710af4baa6ea89f07f5d4bca36dc05476136
Gecko: a93cb087427579663dc1e72b835a35cbcf9baaba
Gonk: a19052e4389c3ae2d8fc3e7a74a475401baacc56
Version: 44.0 (2.5) 
Firmware Version: D5803_23.1.A.1.28_NCB.ftf
User Agent: Mozilla/5.0 (Mobile; rv:44.0) Gecko/44.0 Firefox/44.0

Result:
The song plays correctly through bluetooth devices.

Comment 2

[Adam Alldredge [:AdamA][Inactive]]

Attachment: amr.amr

Comment 3

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

The changes for Bug 948267 seem to have caused this issue.

Mozilla-inbound Regression Window

Last Working 
Environmental Variables:
Device: Flame 2.6
BuildID: 20160112052651
Gaia: 3c97d6a8ac5a69662e1e2c22a84ea59bf50c305e
Gecko: 151695836c37eb591dab55cdb696d620b7092039
Version: 46.0a1 (2.6) 
Firmware Version: v18D
User Agent: Mozilla/5.0 (Mobile; rv:46.0) Gecko/46.0 Firefox/46.0

First Broken 
Environmental Variables:
Device: Flame 2.6
BuildID: 20160112064942
Gaia: 3c97d6a8ac5a69662e1e2c22a84ea59bf50c305e
Gecko: 592fc90e655a1ebd3968300b5ed6261d24ed4065
Version: 46.0a1 (2.6) 
Firmware Version: v18D
User Agent: Mozilla/5.0 (Mobile; rv:46.0) Gecko/46.0 Firefox/46.0

Last Working gaia / First Broken gecko - Issue DOES occur
Gaia: 3c97d6a8ac5a69662e1e2c22a84ea59bf50c305e
Gecko: 592fc90e655a1ebd3968300b5ed6261d24ed4065

First Broken gaia / Last Working gecko - Issue does NOT occur
Gaia: 3c97d6a8ac5a69662e1e2c22a84ea59bf50c305e
Gecko: 151695836c37eb591dab55cdb696d620b7092039

Gecko Pushlog: http://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=151695836c37eb591dab55cdb696d620b7092039&tochange=592fc90e655a1ebd3968300b5ed6261d24ed4065

Comment 4

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

JW can you please take a look at this issue.  The changes for bug 948267 seem to have caused it.

Comment 5

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

I can repro the bug on flame.

Comment 6

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

Attachment: 1242783_fix_underrun.patch

Increase audio buffer to avoid underrun and ticking noise.

Comment 7

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

Hi Jayme,
I increase the capacity of audio buffer from 1s to 2s which works for me on flame. Not sure if it works as good on Aries. Can you apply the patch to see if it fix the problem for you? Thanks.

Comment 8

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

JW, I made a build with the patch and the issue is fixed.

Comment 9

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

I add some logs to show the number of frames requested by the data callback in AudioStream::DataCallback:

I/Gecko   (17933): 2016-02-01 06:38:44.430686 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.431685 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.432114 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.432543 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.432998 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.433675 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.434085 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.434516 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.434921 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.435651 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.440749 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.441551 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.442196 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.443947 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.444403 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.444805 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.445212 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.445925 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.446300 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.446710 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.447106 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.447703 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.448126 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.448507 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.448873 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.449472 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.449841 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.450207 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.450604 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.451169 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.451498 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.451848 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.452190 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.452705 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.468852 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.470300 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.471720 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.474411 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.475935 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.476663 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.477658 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.478678 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.479444 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.481805 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.483234 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.484434 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.485603 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.487552 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.488651 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.490657 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.493032 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.494136 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.495169 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.496332 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200
I/Gecko   (17933): 2016-02-01 06:38:44.497671 UTC - [0xaf7afb80]: W/AudioStream af7a61d0 suro DataCallback(0) frames=200

We can see libcubeb asks for (200 * 55 = 11000) frames within (44.497671 - 44.430686 = 0.066985) seconds and therefore underrunning the audio queue for MDSM only buffers around 1s (8000 frames) when playing amr.amr (rate=8000). Though I can increase the audio buffer of MDSM from 1s to 2s to avoid underrun. But I am not sure if this is a normal behavior to BT devices.

Comment 10

[Matthew Gregan [:kinetik]]

It seems like quite a large buffer, but not completely unsurprising for a "high latency" sink like BT (I think the minimum is on the order of ~350ms for these, plus whatever extra buffering each layer in the audio stack adds).

libcubeb needs a way to signal that the latency requested via cubeb_stream_init wasn't satisified - I think we ask for a 100ms buffer by default, but since we buffer 1s at the MDSM level we're able to handle buffers up to that size without problem.  libcubeb should signal the real buffer size back to the caller somehow so it can adjust buffers as necessary (as in this case, where we'd need to buffer at least 1.375s of audio).

That's more work than increasing the MDSM buffer to 2s though.

Comment 11

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

Before bug 948267, we buffered 1s in the audio queue of MDSM and 1s in the circular buffer of AudioStream. So we were effectively buffering 2s in total. However bug 948267 removed the use of the circular buffer and we still buffered only 1s in the audio queue of MDSM. So we are effectively buffering only 1s after bug 948267 and cause audio underrun for some high latency audio devices.

We should increase the audio buffer to 2s for MDSM to preserve the buffering behavior of pre-bug 948267.

Comment 12

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

Btw, when audio is captured, there is no AudioStream involved. We should only buffer 1s for MDSM to preserve the same buffering behavior of pre-bug 948267.

Comment 13

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

Attachment: MozReview Request: Bug 1242783. Part 1 - per comment 11, increase mAmpleAudioThresholdUsecs to 2s to avoid audio underrun when BT is connected. r=kinetik.

Review commit: https://reviewboard.mozilla.org/r/40325/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/40325/

Comment 14

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

Attachment: MozReview Request: Bug 1242783. Part 2 - per comment 12, buffer only 1s when audio is captured. r=kinetik.

Review commit: https://reviewboard.mozilla.org/r/40327/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/40327/

Comment 15

[Matthew Gregan [:kinetik]]

Comment on attachment 8731035 [details]
MozReview Request: Bug 1242783. Part 1 - per comment 11, increase mAmpleAudioThresholdUsecs to 2s to avoid audio underrun when BT is connected. r=kinetik.

https://reviewboard.mozilla.org/r/40325/#review36865

Comment 16

[Matthew Gregan [:kinetik]]

Comment on attachment 8731036 [details]
MozReview Request: Bug 1242783. Part 2 - per comment 12, buffer only 1s when audio is captured. r=kinetik.

https://reviewboard.mozilla.org/r/40327/#review36867

Comment 17

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

(In reply to Matthew Gregan [:kinetik] from comment #15)
> Comment on attachment 8731035 [details]
> MozReview Request: Bug 1242783. Part 1 - per comment 11, increase
> mAmpleAudioThresholdUsecs to 2s to avoid audio underrun when BT is
> connected. r=kinetik.
> 
> https://reviewboard.mozilla.org/r/40325/#review36865

Can you give some comments for canceling the review? Thanks.

Comment 18

[Matthew Gregan [:kinetik]]

Comment on attachment 8731035 [details]
MozReview Request: Bug 1242783. Part 1 - per comment 11, increase mAmpleAudioThresholdUsecs to 2s to avoid audio underrun when BT is connected. r=kinetik.

https://reviewboard.mozilla.org/r/40325/#review36877

Comment 19

[Matthew Gregan [:kinetik]]

(In reply to JW Wang [:jwwang] from comment #17)
> Can you give some comments for canceling the review? Thanks.

Sorry, it was supposed to be an r+.  Blame MozReview's UI.

Comment 20

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

Thanks! I also have some problems with MozReview's UI which is not very ease of use.

Comment 21

[Maire Reavy [:mreavy]]

[Tracking Requested - why for this release]:
This is a regression caused by Bug 948267, which landed during the Fx 46 Nightly cycle.  I'm about to close Bug 1253296 as a dup of this bug.  (1253296 has the right tracking info.)

Comment 23

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/1be121a3e746
https://hg.mozilla.org/integration/mozilla-inbound/rev/1b7694d14856

Comment 24

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/1be121a3e746
https://hg.mozilla.org/mozilla-central/rev/1b7694d14856

Comment 25

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

Need to uplift to 46.

Comment 26

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

Comment on attachment 8731035 [details]
MozReview Request: Bug 1242783. Part 1 - per comment 11, increase mAmpleAudioThresholdUsecs to 2s to avoid audio underrun when BT is connected. r=kinetik.

Approval Request Comment
[Feature/regressing bug #]: 948267
[User impact if declined]: glitchy audio might be experienced when some high latency audio devices/cards are used (e.g. BT headphones)
[Describe test coverage new/current, TreeHerder]:TreeHerder + manual test
[Risks and why]: very low for the change is quite simple
[String/UUID change made/needed]:none

Comment 27

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

Comment on attachment 8731036 [details]
MozReview Request: Bug 1242783. Part 2 - per comment 12, buffer only 1s when audio is captured. r=kinetik.

Approval Request Comment
[Feature/regressing bug #]:948267
[User impact if declined]:glitchy audio might be experienced when some high latency audio devices/cards are used (e.g. BT headphones)
[Describe test coverage new/current, TreeHerder]:TreeHerder + manual test
[Risks and why]: very low for the change is quite simple
[String/UUID change made/needed]:none

Comment 28

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

Tracked for Fx46+ as it's an audio playback issue.

Comment 29

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

Comment on attachment 8731035 [details]
MozReview Request: Bug 1242783. Part 1 - per comment 11, increase mAmpleAudioThresholdUsecs to 2s to avoid audio underrun when BT is connected. r=kinetik.

Was manually verified, Aurora47+, Beta46+

Comment 30

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

https://hg.mozilla.org/releases/mozilla-aurora/rev/0b96a3758fde
https://hg.mozilla.org/releases/mozilla-aurora/rev/4951be326d7b

Comment 31

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

https://hg.mozilla.org/releases/mozilla-beta/rev/0b581544f541
https://hg.mozilla.org/releases/mozilla-beta/rev/bfbf987bd9ca