1121148 - Opus audio streaming start delayed by 30 seconds in Firefox 36

Status: VERIFIED FIXED

(Core :: Audio/Video, defect)

Description

[yo]

User Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:36.0) Gecko/20100101 Firefox/36.0
Build ID: 20150109153938

Steps to reproduce:

My website http://radiobattletoads.com uses a Ogg/Opus audio stream. I try to play the radio by pressing the play button.

Alternatively, I have prepared a test in http://radiobattletoads.com/test_mozilla.php (please reload for each try)


Actual results:

The audio is delayed by 30 seconds in Firefox 36 after pressing the play button. It works fine in Firefox 35 and older. The dialog that appears is just a warning to Firefox 36 users. You can close it.

It only happens with the Opus stream. The mp3 stream works fine. In the test, if you press the playu button for the mp3 version, it starts right away.


Expected results:

The audio should start in 1 or 2 seconds, as in previous versions. But I have to wait up to 30 seconds.

Comment 1

[ramonrey]

User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:36.0) Gecko/20100101 Firefox/36.0
Build ID: 20150112201205

I confirmed this problem in the Mac platform and with both Opus and Mp3 streams in the test the user has provided.

Comment 2

[Loic]

I'm able to reproduce the issue with the MP3 stream too.

Regression range:
good=2014-11-12
bad=2014-11-13
http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=688f821edcd4&tochange=ab137ddd3746

Suspected bug:
Bug 1091008 - MediaDecoderStateMachine::HasLowUndecodedData doesn't work for MSE

Comment 3

[Alice0775 White]

In local build:
Last Good:  d938d5ac11e3 + fda1b680307f
First Bad:  deae19d73b34 + fda1b680307f

Triggered by: 
	deae19d73b34	Bobby Holley — Bug 1091008 - Reimplement HasLowUndecodedData in terms of GetBuffered. r=cpearce
Since GetBuffered now has a sane implementation for MSE, this should
make this function sane for MSE as well.

Comment 4

[Sylvestre Ledru [:Sylvestre]]

Regression, tracking.

Comment 5

[Bobby Holley (:bholley)]

This is a great bug report - thanks.

Comment 6

[Bobby Holley (:bholley)]

Attachment: Part 1 - Move constants that we should not be using directly into a namespace. v1

This lets us avoid using them accidentally in place of their member-variable
equivalents.

Comment 7

[Bobby Holley (:bholley)]

Attachment: Part 2 - Make QUICK_BUFFERING_LOW_DATA_USECS a member variable and adjust it appropriately. v1

Comment 8

[Bobby Holley (:bholley)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=e43a50ee0e10

Comment 9

[Bobby Holley (:bholley)]

I realize I never explained what's going on - the issue is that our ample audio threshold ends up lower than our quickbuffering threshold, so we stay in quickbuffering mode while never decoding more audio because NeedToDecodeAudio returns false.

Comment 10

[Bobby Holley (:bholley)]

remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/736a8a49caab
remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/9577ee22f9d4

Comment 11

[Bobby Holley (:bholley)]

Comment on attachment 8552832 [details] [diff] [review]
Part 2 - Make QUICK_BUFFERING_LOW_DATA_USECS a member variable and adjust it appropriately. v1

Applies to both patches.

Approval Request Comment
[Feature/regressing bug #]: bug 1091008
[User impact if declined]: Bad playback experience
[Describe test coverage new/current, TreeHerder]: None
[Risks and why]: Very low risk.
[String/UUID change made/needed]: None

Comment 12

[Bobby Holley (:bholley)]

Thank you jorge, ramonrey, Loic, and Alice for the excellent detective work in finding this bug! It made it very easy to fix, and helped us to avoid shipping a bad regression. :-)

Comment 13

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/736a8a49caab
https://hg.mozilla.org/mozilla-central/rev/9577ee22f9d4

Comment 14

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/16ac86430265
https://hg.mozilla.org/releases/mozilla-aurora/rev/abb627d4fb5c

https://hg.mozilla.org/releases/mozilla-beta/rev/1237ddff18be
https://hg.mozilla.org/releases/mozilla-beta/rev/62f7b8ea571f

Comment 15

[Ryan VanderMeulen [:RyanVM]]

Follow-up fix for beta:
https://hg.mozilla.org/releases/mozilla-beta/rev/b3792d13df24

Comment 16

[Ada [:adalucinet]]

Reproduced with Nightly 2015-01-12 on Mac OS X 10.9.5 with both mp3 and opus streams.
Verified as fixed on Fx 36 beta 4 (Build ID: 20150126151838), DevEd 37.0a2 (Build ID: 20150126004016) and Nightly 38.0a1 (Build ID: 20150126030202) e10s enabled/disabled under Mac OS X 10.9.5, Ubuntu 13.10 x64 and Windows 7 x64 - no delay encountered when playing both streams.
Although, on Mac OS X 10.10 with latest Nightly & e10s enabled, this issue is still reproducible (intermittently), but couldn't reproduce with e10s disabled. Any idea?

Comment 17

[Bobby Holley (:bholley)]

(In reply to Alexandra Lucinet, QA Mentor [:adalucinet] from comment #16)
> Although, on Mac OS X 10.10 with latest Nightly & e10s enabled, this issue
> is still reproducible (intermittently), but couldn't reproduce with e10s
> disabled. Any idea?

We should definitely get to the bottom of that, though I am unable to reproduce it. I think it's probably a separate bug.

Can you reproduce the problem with the following environmental variables set?

MEDIA_LOG_SAMPLES=1 NSPR_LOG_MODULES="MediaDecoder:5,MediaSource:5,MediaPromise:5,MP4Demuxer:5,AppleMedia:5"

(The MEDIA_LOG_SAMPLES piece makes things extra verbose, so if the logging is disrupting the timing of the bug, you could try removing that).

Then, file a new bug, attach the log, and needinfo me?

Comment 18

[Ada [:adalucinet]]

(In reply to Bobby Holley (Busy with media, don't ask for DOM/JS/XPConnect things) from comment #17)
> Then, file a new bug, attach the log, and needinfo me?

I was able to reproduce with the requested variables set and logged bug 1126723.
Based on this, changing the status accordingly.