1218157 - Seeking forward during streaming audio causes unreasonable caching and glitches.

Status: VERIFIED FIXED

(Core :: Audio/Video, defect)

Description

[mrmustard1]

User Agent: Mozilla/5.0 (Windows NT 10.0; WOW64; rv:41.0) Gecko/20100101 Firefox/41.0
Build ID: 20151014143721

Steps to reproduce:

1. Visit a streaming audio website.  In this example, www.soundcloud.com.
2. Click play on an audio track
3. Click towards the middle or end of track.



Actual results:

Playback audio stutters, caches, and plays "glitched" (a mixture of audio from two parts of the stream, simultaneously).  On occasion, no audio will play.  On occasion, the audio will return to playing properly after perhaps one to two minutes.

http://www.dailymotion.com/video/x38p6cu_soundcloud-playback-problem_music

Here are console screenshots of what happens when you load and seek through streaming audio tracks:

Firefox 41.0.1 Console Shots:

This is when I first press Play on the track: http://imgur.com/MTq7RRt    At this point, the track is playing properly.

This is when I skip to the middle of the track (31:32), and the problem occurs: http://imgur.com/Yao6XKF   Note all the partial content requests.  The track is buffering and stuttering.

Another shot of the continued partial requests as the track buffers and skips: http://imgur.com/H7707DF   This shot was taken 11 seconds after the initial skip to the middle. (31:43)

The last shot, of when the track actually begins playing properly again (31:57), 25 seconds after the initial skip to the middle: http://imgur.com/WhSE3Ky



Expected results:

Playback audio should have been smooth and flawless.  In fact, in Firefox 40.x, the audio is in fact flawless.  The problem arose with Firefox 41 and is persistent regardless of Flash version.  The problem does not exist in Chrome, IE, or Edge.

On a streaming audio site that allows you to seek forward in tracks, you should (and have been, on Firefox 40.x and earlier versions) be able to skip immediately to the middle or end of a track to hear the audio present at that time point.  In audio tracks that are an hour, or two hours long (mixes, podcasts and radio shows), people will frequently want to seek into the track to sample the different audio being played at that time point.

Comment 1

[mrmustard1]

See also:

https://www.soundcloudcommunity.com/soundcloud/topics/skipping-to-the-middle-of-a-track-causes-stuttering-and-glitchy-audio-chrome-firefox

https://support.mozilla.org/en-US/questions/1089368

Comment 2

[mrmustard1]

It is important to note, and I apologize for leaving it out of the initial report, this problem is not limited to Soundcloud.  For example, you can visit www.traxsource.com, attempt to stream audio, and the error will manifest in exactly the same manner.

Comment 3

[Ryan VanderMeulen [:RyanVM]]

I've been unable to reproduce anything like what you captured in your video with Firefox 41.0.2 on both Windows 10 and Ubuntu 15.10, nor on a current nightly build. I've been testing with https://soundcloud.com/stickybuds/fractal-2015

Does the URL above reproduce the issue for you as well? If not, can you point to a specific one that does so we're for sure looking at the same thing?

Comment 4

[mrmustard1]

Yes, the problem manifests at the URL you supplied.  I opened up that Stickybuds mix, let it play for five seconds, then skipped to the 44:00 mark.  The problem occurred exactly as it has been happening (same behavior as in my Dailymotion video).

For further testing, I opened the same link in Chrome, IE, Edge, and Firefox 40.0.2, did the same "middle-seek" on that Stickybuds mix, and none of them exhibit the error in any manner at all.  The audio starts instantaneously and smoothly from wherever I click in the mix.

This is frustrating, as exactly the same thing is happening with Soundcloud support.  They say they cannot reproduce the error, but the thread I started on their support forums is filled with people having the same problem.

Comment 5

[Ryan VanderMeulen [:RyanVM]]

Yes, that is indeed quite maddening :(

Given the difficulties in reproducing on this end, would you be willing to try helping hunt down the regressing change? Knowing the change that started causing your problems could go a long way to figuring out what's going on. We have a tool that automates the process of downloading and launching different version so all you basically have to do is say whether the build is good or bad or not. If you're willing, check out http://mozilla.github.io/mozregression/

Given that it worked OK with Firefox 40, that means we're looking at about a 6 week window for when it broke, which shouldn't take very long to track down. A command like |mozregression --good-release 40 --bad-release 41| should be all that's need to get started.

Comment 6

[mrmustard1]

Yes, absolutely.  I'll give it a shot and report back when I have more info.  Thanks =)

Comment 7

[Ryan VanderMeulen [:RyanVM]]

Thank you!

Comment 8

[mrmustard1]

OK, I ran the regression and I narrowed it down to one particular revision.  Is there a log file I can send?

Comment 9

[Ryan VanderMeulen [:RyanVM]]

Posting the hg.mozilla.org URL it gave you would be great.

Comment 10

[mrmustard1]

Here you go,

https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=28e6664ad1a16463932d397aaac7f3fbc6bde73b&tochange=9fb9dbd7a0dd018483ca56c725f6eff55012902a

Thank you so much for your help!  =)

Comment 11

[Ryan VanderMeulen [:RyanVM]]

That's extremely helpful information. So this is almost certainly caused by bug 1175768. When I look at that bug, I actually see that other soundcloud-related regression bugs have been filed off it as well. It appears that one issue was actually fixed already for Firefox 42 (due for release next week).

Can you try out a current beta build and see if things are working better?

Comment 12

[Ryan VanderMeulen [:RyanVM]]

Bug 1208953 (also fixed in 42) also looks similar.

Comment 13

[mrmustard1]

Sorry, no dice.  I downloaded and installed 42.0b9, and the problem still persists.  It behaves a bit differently now, though.  It is quicker to "catch up" when you seek to the middle of a track, but it still stutters (though less than before), and glitches (playing back two parts of the stream "mixed" together, like 1/2 second of one part, 1/2 second of another, back and forth, etc.)  The console shows many partial content requests, though fewer than before.

Comment 14

[mrmustard1]

I should add that on shorter tracks (say, <5 min in length), the problem is diminished.  There is some caching while seeking, notably more than Edge, IE or Chrome, but once it "catches up", I am able to seek through without a problem.  If I jump around from track to track, I still get the glitches and stutters, but only once every few tracks.

Comment 15

[Ryan VanderMeulen [:RyanVM]]

[Tracking Requested - why for this release]: Audio playback issues for some users since Firefox 41

Any ideas/suggestions here, jya?

Comment 16

[Ryan VanderMeulen [:RyanVM]]

If you're interested in yet more trials, I pinged jya on IRC about this and he said that Fx43 (the current Developer Edition) has seen even more possibly-related fixes. Would you be willing to try that out as well? And for bonus points, might as well complete the pre-release trifecta and try out a recent nightly as well (tracking Firefox 44).

https://www.mozilla.org/en-US/firefox/developer/
https://nightly.mozilla.org/

Comment 17

[mrmustard1]

Yep, sort of having fun with this, I will try 43 and 44 and get back to you. =)

Comment 18

[mrmustard1]

Firefox 43 behaves exactly the same as 42.  The same small improvements introduced with 42 are there, but overall the problem persists.  Most tracks cache, stutter and glitch.

Firefox 44 is worse... seeking forward in a track did absolutely nothing on most tracks I tried, both short (<5 mins), and long (90 mins +).  The console showed no content requests at all, for most seeks.  Perhaps one in ten tracks behaved normally, or gave me the stutter/glitching.  All other tracks just sat silent when I tried to skip to the middle.

Comment 19

[Jean-Yves Avenard [:jya]]

Firefox 44 uses a completely different code path to 43 and earlier (which on windows uses Windows's own Direct Show).

Unfortunate that the new MP3Demuxer doesn't seek properly on those streams.

Eugene, is there anything special with those streams?

Will investigate if there's a short term solution we can apply on Windows Direct show decoder.

Comment 20

[Jean-Yves Avenard [:jya]]

Could you please try the following build?

https://ftp.mozilla.org/pub/firefox/nightly/2015-10-01-03-02-36-mozilla-central/firefox-44.0a1.en-US.win32.installer.exe

I believe this build contains a fix that would resolve the issue you mentioned, and before we made the new MP3Decoder the default.

If that does fix it for you, uplifting the change to 43 (and maybe even 42) would be easy.

Thank you very much for your help; you're awesome

Comment 21

[mrmustard1]

Unfortunately, that version of Nightly still suffers from the stuttering, glitching and "partial content requests" of version 41, 42, and 43.  The "seeking and doing nothing" problem is gone though; I can seek forward in tracks, but of course, they then stutter and skip =/

Comment 22

[Jean-Yves Avenard [:jya]]

Oh... the reason for Nightly not working is because it doesn't contain the new fast seek change (bug 1163667).
So seek *will* work in tomorrow's nightly (maybe tonight even), but currently it has to read and demux all audio samples until it reaches the seek target ; and that can take a fair amount of time 

Seeking to 44 minutes took just above 1 minute here, but there was no audio glitch of any kind and playback resumed very nicely.

In the mean time http://archive.mozilla.org/pub/firefox/tinderbox-builds/mozilla-central-win32/1445895309/firefox-44.0a1.en-US.win32.installer.exe will fix the issue. Not going to help for 42 and 43 however; 

It takes less than 2s to seek here, and there's no interruption (though I can't reproduce your issue in windows 10 in 42)

Comment 23

[Jean-Yves Avenard [:jya]]

oh I can reproduce on a win8 VM!

Comment 24

[mrmustard1]

OK, great.  I will use the 44.0 for now, and watch the nightly for a build that allows the seek to work.  Is this then something that would be fixed in 42 or 43, or would it be only for 44 when that comes out?

Comment 25

[Jean-Yves Avenard [:jya]]

(In reply to mrmustard1 from comment #24)
> OK, great.  I will use the 44.0 for now, and watch the nightly for a build
> that allows the seek to work.  Is this then something that would be fixed in
> 42 or 43, or would it be only for 44 when that comes out?

so I assume that you tested it and found it working.

Warning, that mozilla-central build above will not auto-update.

Comment 26

[mrmustard1]

I'm sorry, yeah I got ahead of myself =)  The nightly in your last link works perfectly.  Seeking is instant, no stuttering or glitching on tracks of any length.

Comment 27

[Ryan VanderMeulen [:RyanVM]]

(In reply to mrmustard1 from comment #24)
> Is this then something that would be fixed in 42 or 43, or would it be only for 44 when that comes out?

Unfortunately, 42 is too close to release for any last-second fixes unless the issue is extremely critical. However, the door is still open for a low-risk fix to land on 43.

Comment 28

[Eugen Sawin [:esawin]]

I can reproduce on Window 8, Firefox 41 on long streams.
Enabling the new demuxer by setting media.mp3.enabled=true fixes it (but as mentioned with slow seeking only), so there could be an issue with the old demuxer.

We could trade off seeking performance for fixed playback after seeking by enabling the new demuxer by default.
I'm not very comfortable with doing that without all the patches that have landed in 43 and 44 and I would like to let bug 1163667 (seeking performance improvement) bake some more on Nightly before uplifting - preferably it should ride trains.

Comment 29

[Jean-Yves Avenard [:jya]]

I think I finally understand what's going on...
and it is indeed a consequence of bug 1175768.

Prior 1175768, NotifyDataArrived would be called on the main thread, before MediaResource::Read() returned.
This allowed to parse the data to update the duration without ever affecting the MediaCache and MediaResource.

Now NotifyDataArrived is queued to run on the reader's task queue. After a seek on a long stream we would start reading at say offset 50MB ; then the NotifyDataArrived from the old read done prior the seek at 8MB arrive and the DirectShowReader::NotifyDataArrived starts a read at 8MB ; that causes the MediaResource to seek and issue a new range request.
Then the MP3 decoder resumes the read at 50MB ; this isn't a continuity of the previous read, so new range request ; NotifyDataArrived from the previous read happens

Range requests are very slow..

And this cycle continues.

Now, the fix here is simple. Modify DirectShowReader::NotifyDataArrived to only update the duration if it's not set. So we stop doing continuously out of order reads
Do we need to continuously update the duration anyway?


It is a pity this bug wasn't reported before, it's been ever since 41 and it's the same issue that we have in the gstreamer (which is the one that has been most reported) and the Apple MP3 reader.
I had been trying to figure out what was going on but never had an easily reproducible case :(

Too bad we can't fix it in 42.. It's really an easy, no risk fix.

MP3 playback is just broken as it is :(

Ryan there's no way around this ?

Comment 30

[Ryan VanderMeulen [:RyanVM]]

(In reply to Jean-Yves Avenard [:jya] from comment #29)
> Ryan there's no way around this ?

Your best bet is emailing release-drivers@ ASAP if you want to argue something for 42, but given that the release candidate build has already been created, you're going to have to make a pretty convincing argument to get them to spin a new build for it.

Comment 31

[Sylvestre Ledru [:Sylvestre]]

Tracking because I am sure I am going to hear more about this one soon.

Comment 32

[Jean-Yves Avenard [:jya]]

Attachment: Only ever read from cached data in NotifyDataArrived.

The logic of queuing NotifyDataArrived and read data there was fundamentally flawed as we would continually perform reads from the same MediaResource at two different ends.
This would cause repetitive seeks and data being removed from the media cache. Worse, a read in NotifyDataArrived would cause another NotifyDataArrived to be scheduled.

As range-request are extremely slow, it would result in stutters and constant interruptions.

Comment 33

[mrmustard1]

(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #27)
> Unfortunately, 42 is too close to release for any last-second fixes unless
> the issue is extremely critical. However, the door is still open for a
> low-risk fix to land on 43.

Thanks very much for the info, and thanks to all for their help on this!

Comment 34

[Jean-Yves Avenard [:jya]]

(In reply to mrmustard1 from comment #33)
> Thanks very much for the info, and thanks to all for their help on this!

Here is a 42 build (beta) with the fix included.
http://archive.mozilla.org/pub/firefox/try-builds/[e-mail]-cf4088e8f636bf2f0870519eefbfbb4caf14a211/try-win32/firefox-42.0.en-US.win32.installer.exe

Could you let me know how that works for you? (even though I'm highly confident it removed the problem).

Who knows, the sheriffs and power to be may have a change of heart and allow the fix to go in :)

Comment 35

[Jean-Yves Avenard [:jya]]

Attachment: Only ever read from cached data in NotifyDataArrived.

The logic of queuing NotifyDataArrived and read data there was fundamentally flawed as we would continually perform reads from the same MediaResource at two different ends.
This would cause repetitive seeks and data being removed from the media cache. Worse, a read in NotifyDataArrived would cause another NotifyDataArrived to be scheduled.

As range-request are extremely slow, it would result in stutters and constant interruptions.

Beta(42)/Aurora(43) patch.

Comment 36

[mrmustard1]

(In reply to Jean-Yves Avenard [:jya] from comment #34)
 
> Here is a 42 build (beta) with the fix included.
> http://archive.mozilla.org/pub/firefox/try-builds/[e-mail]-
> cf4088e8f636bf2f0870519eefbfbb4caf14a211/try-win32/firefox-42.0.en-US.win32.
> installer.exe
> 
> Could you let me know how that works for you? (even though I'm highly
> confident it removed the problem).

Yes, that build works absolutely fine, no sign of the problem.  Thank you!

Comment 37

[Jean-Yves Avenard [:jya]]

awesome, thank you for reporting so quickly

Comment 38

[Jean-Yves Avenard [:jya]]

Comment on attachment 8679763 [details] [diff] [review]
Only ever read from cached data in NotifyDataArrived.

Applying for beta, just in case you have a change of heart. Seeing the length of the thread complaining the problem in soundhound forum.
We've had lots of bug reports due to regression introduced by bug 1175768 ; this bug fix the core problem.

Approval Request Comment
[Feature/regressing bug #]: 1175768
[User impact if declined]: MP3 streaming will stutter, stop or just error ; enormous amount of network requests, it even caused very high CPU usage (which bug 1208953 partially addressed).
[Describe test coverage new/current, TreeHerder]: Local test ; try run
[Risks and why]: Low, this is a continuation of bug 1208953 which was uplifted to beta recently. It's pretty much a return to the behaviour before bug 1175768 went in: we don't initiate out of order new reads.
Also, don't be alarmed by the size of the patch, many of the components it touches have actually be obsoleted and are no longer in use (in particular the most important one I believe: WebMReader)
[String/UUID change made/needed]: None

Comment 39

[Jean-Yves Avenard [:jya]]

I should add that the platform most likely to benefit isn't windows but Linux users with gstreamer as this is the target where we had the highest number of regressions reported following 1175768

Comment 40

[Sylvestre Ledru [:Sylvestre]]

A few things:
* For now, we are not planning to do a RC2. However, our past experiences demonstrate that we usually do a second RC.
* As you expected, I freak out about the size of the patch. If the updated components are obsolete, why are you updating it? Not possible to make a smaller patch ?

By the way, thanks mrmustard1 for the quality of this bug report!

Comment 41

[Sylvestre Ledru [:Sylvestre]]

Comment on attachment 8679763 [details] [diff] [review]
Only ever read from cached data in NotifyDataArrived.

m-beta has moved to m-release last Monday

Comment 42

[mrmustard1]

(In reply to Sylvestre Ledru [:sylvestre] from comment #40)

> By the way, thanks mrmustard1 for the quality of this bug report!

It was my pleasure.  You guys are on the ball here and I was glad to help out.

Comment 43

[Jean-Yves Avenard [:jya]]

(In reply to Sylvestre Ledru [:sylvestre] from comment #40)
> A few things:
> * For now, we are not planning to do a RC2. However, our past experiences
> demonstrate that we usually do a second RC.
> * As you expected, I freak out about the size of the patch. If the updated
> components are obsolete, why are you updating it? Not possible to make a
> smaller patch ?

because if you look carefully, it's all the same logic everywhere.
The code was duplicated in multiple places across readers.

And I'm highly confident the fix is correct (and seeing that bug 1208953 made it to 42 which already started this fix). Was kind of a eureka moment last night when I realised what was happening.

42 is a major new release in that it's the first release that introduce an almost complete overall of our media architecture, including complete rewrite of MSE. So I've kept the door open to turning off those new players and revert back to the previous ones "just in case". This is a continuation of that logic.
It's too bad that this 41 regression managed to slip through (I blame Whistler for that!)

> 
> By the way, thanks mrmustard1 for the quality of this bug report!

indeed, wouldn't have happened without his excellent STR. We've had months of reports of broken behaviours with either MP3 or GStreamer on linux; none of them were reproducible on my machine so I always went blind.

Comment 44

[Sylvestre Ledru [:Sylvestre]]

OK, merci!
As we already shipped 41 with this bug, I don't think this bug is critical enough to start a second rc. However, if we have to do one, we might take this one as ride along.

However, I would like this patch to be reviewed and landed in m-c & m-a asap.

Comment 45

[Jean-Yves Avenard [:jya]]

that's the try run: https://treeherder.mozilla.org/#/jobs?repo=try&revision=d412ddbe281f

Comment 46

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

Comment on attachment 8679763 [details] [diff] [review]
Only ever read from cached data in NotifyDataArrived.

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

::: dom/media/directshow/DirectShowReader.cpp
@@ +402,3 @@
>    for (const auto& interval : intervals) {
>      RefPtr<MediaByteBuffer> bytes =
> +      resource->MediaReadAt(interval.mStart, interval.Length());

Does this mean that every time a segment downloads, we reparse the entire downloaded data? Can we memoize the parsed result, to make this cheaper?

Or would we be better to just remove all these old readers and use the MediaFormatReader for All The Things?

Comment 47

[Jean-Yves Avenard [:jya]]

(In reply to Chris Pearce (:cpearce) from comment #46)
> Comment on attachment 8679763 [details] [diff] [review]
> Only ever read from cached data in NotifyDataArrived.
> 
> Review of attachment 8679763 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> ::: dom/media/directshow/DirectShowReader.cpp
> @@ +402,3 @@
> >    for (const auto& interval : intervals) {
> >      RefPtr<MediaByteBuffer> bytes =
> > +      resource->MediaReadAt(interval.mStart, interval.Length());
> 
> Does this mean that every time a segment downloads, we reparse the entire
> downloaded data? Can we memoize the parsed result, to make this cheaper?

This is what the NotifyDataArrivedFilter does the line above (bug 1208953): filter what has already been parsed.

We only ever read the same data once.


> 
> Or would we be better to just remove all these old readers and use the
> MediaFormatReader for All The Things?
This is done in Nightly; except for Windows XP

Comment 48

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/8adc6bf10f95

Comment 49

[Liz Henry (:lizzard) (relman/hg->git project)]

Comment on attachment 8679763 [details] [diff] [review]
Only ever read from cached data in NotifyDataArrived.

Let's land this in aurora.  If we can stop the gstreamer crashes and other issues, or mitigate them in 43, that's going to be great.

Comment 50

[Sylvestre Ledru [:Sylvestre]]

Comment on attachment 8679763 [details] [diff] [review]
Only ever read from cached data in NotifyDataArrived.

Let's take that in 42 rc2.

Comment 51

[Sylvestre Ledru [:Sylvestre]]

Why I changed my mind: we are going to do a rc2 for bug 1205083.
soundcloud is an important website and we basically broke it.
If this introduces an regression, I am sure that the media team will work during the week end to fix it.

Comment 52

[Jean-Yves Avenard [:jya]]

(In reply to Sylvestre Ledru [:sylvestre] from comment #51)
> Why I changed my mind: we are going to do a rc2 for bug 1205083.
> soundcloud is an important website and we basically broke it.
> If this introduces an regression, I am sure that the media team will work
> during the week end to fix it.

Done deal.
It's a long week-end here, but I'll take my laptop with me and will be available should any shit hit the fan.

Comment 53

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/41fdefd640f3

Comment 54

[Jean-Yves Avenard [:jya]]

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

Comment 55

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/8adc6bf10f95

Comment 56

[Camelia Badau [:cbadau], Desktop Test Engineering]

We tested on Firefox 42 RC Build 2 (buildID: 20151029151421) and on Windows 7 64bit we encountered the crash from bug 788423; here is the actual crash report: https://crash-stats.mozilla.com/report/index/03eff438-5e7e-4073-8f8c-604532151030

Comment 57

[Jean-Yves Avenard [:jya]]

(In reply to Camelia Badau, QA [:cbadau] from comment #56)
> We tested on Firefox 42 RC Build 2 (buildID: 20151029151421) and on Windows
> 7 64bit we encountered the crash from bug 788423; here is the actual crash
> report:
> https://crash-stats.mozilla.com/report/index/03eff438-5e7e-4073-8f8c-
> 604532151030

I can't see how a fix in our MP3 decode code could be inducing a flash plugin crash. Must be a coincidence.

Comment 58

[Jean-Yves Avenard [:jya]]

(In reply to Camelia Badau, QA [:cbadau] from comment #56)
> We tested on Firefox 42 RC Build 2 (buildID: 20151029151421) and on Windows
> 7 64bit we encountered the crash from bug 788423; here is the actual crash
> report:
> https://crash-stats.mozilla.com/report/index/03eff438-5e7e-4073-8f8c-
> 604532151030

Could you please also perform tests on Linux and Mac?

All platforms use a different software path to decode MP3 and all needs to be exercised.
Mac uses the Core Media player
Linux uses gstreamer
and Windows uses DirectShow.

This fix corrects all of those. I manually verified that it worked on all; but more tests the better.

Thank you

Comment 59

[Vasilica Tamas, QA [:vtamas]]

Tested again with a clean profile on Firefox 42 RC build 2 (20151029151421) and Firefox 43 Beta 1 (20151102024757) under Windows 7 64-bit and Windows 10 64-bit but I have not managed to reproduce the crash from Comment 56 this time.

Verified also on Mac OS X 10.10.4 and Linux 13.10 64-bit and I have not encountered any issues neither across this platforms.

Based on this testing I am marking this bug as Verified.

Comment 60

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

status44 should be fixed based on comment 55.