Bandcamp.com audio playback stalls when seeking

RESOLVED FIXED in Firefox 42

Status

()

Core
Audio/Video: Playback
P1
normal
RESOLVED FIXED
2 years ago
2 years ago

People

(Reporter: cpeterson, Assigned: jya)

Tracking

({regression})

unspecified
mozilla44
Unspecified
All
regression
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox41 wontfix, firefox42+ fixed, firefox43 fixed, firefox44 fixed, firefox-esr38 unaffected)

Details

(URL)

Attachments

(1 attachment)

(Reporter)

Description

2 years ago
[Tracking Requested - why for this release]:

@ jya, I think this is a regression from bholley's NotifyDataArrived bug 1175768 in Firefox 41. I bisected this regression to this pushlog:

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

STR:
1. Load https://beyondbeyondisbeyondrecords.bandcamp.com/album/holy-water-pool
2. Press the PLAY button, if necessary.
3. As the music starts to play, click and drag the play position control to seek.
4. Seek forward about 2/3 into the song.
5. Seek back about 1/3 into the song.
6. GOTO 4

RESULT:
After seeking a couple times, playback will stall. Press the PAUSE and PLAY button will do nothing.
Flags: needinfo?(jyavenard)
(Reporter)

Updated

2 years ago
Blocks: 1208955
(Assignee)

Comment 1

2 years ago
what platform is that on?
(Assignee)

Comment 2

2 years ago
if it's about dragging the slider; it's likely the same as bug 1089586 which I've just fixed.

When you drag the slider; it issues lots of seek requests which are treated sequentially by the MediaFormatReader ; on the video found in bug 1089586 ; dragging the cursor from the end to 0:00 in 3s results in playback resuming after 4m 45s on my mac.

With the patch applied only 3 seeks are being processed and it completes within 5s

Comment 3

2 years ago
I can reproduce.
https://hg.mozilla.org/mozilla-central/rev/6256ec9113c115141aab089c45ee69438884b680
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:44.0) Gecko/20100101 Firefox/44.0 ID:20150927030300
(Reporter)

Comment 4

2 years ago
I can reproduce the stall on both OS X and Windows.
Depends on: 1089586
Flags: needinfo?(jyavenard)
OS: Unspecified → All
Priority: -- → P1
(Assignee)

Comment 5

2 years ago
Actually, I had media.mp3.enabled which enables the new MediaFormatReader architecture ; so bug 1089586 wouldn't help here.

I can't reproduce the problem locally , even using a 3G modem
No longer depends on: 1089586
(Assignee)

Comment 6

2 years ago
can't reproduce , tried windows, mac 41, 43 and 44.
(Assignee)

Comment 7

2 years ago
ok.. reproduced it in nightly on mac ; but playback always ends up resuming if you wait long enough: took about 1 minute in one case.

And this is the old MP3 playback which we are aiming to remove :(
(Assignee)

Comment 8

2 years ago
This seems weird:
863514624[1474901a0]: AppleMP3Reader::NotifyDataArrived(19001, 2293760)
863514624[1474901a0]: Updating media duration to 218406219us
863514624[1474901a0]: AppleMP3Reader::NotifyDataArrived(1478, 1179648)
863514624[1474901a0]: AppleMP3Reader::NotifyDataArrived(21585, 2293760)
863514624[1474901a0]: Updating media duration to 218406156us
863789056[1385c5600]: AppleMP3Reader::NotifyDataArrived(8017, 1179648)
906493952[166469980]: AppleMP3Reader::NotifyDataArrived(24891, 2293760)
906493952[166469980]: Updating media duration to 218406072us
906493952[166469980]: AppleMP3Reader::NotifyDataArrived(8750, 1179648)
863514624[1474901a0]: AppleMP3Reader::NotifyDataArrived(28669, 2293760)
863514624[1474901a0]: Updating media duration to 218406231us
906493952[166469980]: AppleMP3Reader::NotifyDataArrived(8967, 1179648)
906493952[166469980]: AppleMP3Reader::NotifyDataArrived(31412, 2293760)
906493952[166469980]: Updating media duration to 218406158us
863789056[1385c5600]: AppleMP3Reader::NotifyDataArrived(14623, 1179648)
862367744[14748fd80]: AppleMP3Reader::NotifyDataArrived(32355, 2293760)
862367744[14748fd80]: Updating media duration to 218406137us
906493952[166469980]: AppleMP3Reader::NotifyDataArrived(18886, 1179648)
863514624[1474901a0]: AppleMP3Reader::NotifyDataArrived(36873, 2293760)

We can see the the MediaResource reads back and forth the same content.

This is very likely the same issue as originally mentioned in bug 1184429. This was resolved by not using WebMReader.

The explanation was described in bug 1184429 comment 6.

One way to get around it would be to always cache and dispatch NotifyDataArrived so its always within a boundary of a cache block.

JW, got any advice?
Flags: needinfo?(jwwang)
See Also: → bug 1184429
(Assignee)

Updated

2 years ago
Flags: needinfo?(jwwang)
(Assignee)

Comment 9

2 years ago
Created attachment 8667122 [details] [diff] [review]
[mp3] Don't parse data we've already parsed.

NotifyDataArrived may be called again due to reads performed in NotifyDataArrived ; causing stall and serious slowdowns.
Attachment #8667122 - Flags: review?(cpearce)
(Assignee)

Updated

2 years ago
Assignee: nobody → jyavenard
(Assignee)

Comment 10

2 years ago
green try: https://treeherder.mozilla.org/#/jobs?repo=try&revision=e986073ce02e
(Assignee)

Comment 11

2 years ago
Eugene, seeking is still quite slow even with the new MP3Demuxer ; 

seeking is done by decoding all frames until we've counted the right amount in MP3TrackDemuxer::ScanUntil

FastSeek only appears to be used for seeking backward. Why is that ?
Can't there be a faster way, like simply guessing the bitrate?

Both Safari and Chrome seeks instantly on those mp3; but it can take up over 10s with firefox.
Flags: needinfo?(esawin)
Comment on attachment 8667122 [details] [diff] [review]
[mp3] Don't parse data we've already parsed.

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

You've got the exact same code in everything except the MediaCodecReader. Seems like a helper function could be used here to reduce the amount of code we have.

::: dom/media/MP3FrameParser.h
@@ +230,5 @@
> +
> +private:
> +  media::IntervalSet<int64_t> mIntervals;
> +};
> +  

Trailing whitespace.
Attachment #8667122 - Flags: review?(cpearce) → review+
(Assignee)

Comment 13

2 years ago
(In reply to Chris Pearce (:cpearce) from comment #12)
> Comment on attachment 8667122 [details] [diff] [review]
> [mp3] Don't parse data we've already parsed.
> 
> Review of attachment 8667122 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> You've got the exact same code in everything except the MediaCodecReader.
> Seems like a helper function could be used here to reduce the amount of code
> we have.

just enough tiny difference in member name to make it different.

Again, this should have been done just as well in the MediaDecoderReader code that dispatch the call to NotifyDataArrivedInternal (which would have benefited the now unused WebMReader too)

Comment 14

2 years ago
https://hg.mozilla.org/integration/mozilla-inbound/rev/7fc9c1614602
(Reporter)

Comment 15

2 years ago
Jean-Yves, should we uplift this fix to Aurora 43 or even Beta 42, since it fixes a regression from 41?
status-firefox41: affected → wontfix
Flags: needinfo?(jyavenard)
(Assignee)

Comment 16

2 years ago
I think so.. maybe let it bake in central and aurora for a few days to make sure (though I'm pretty confident).

If you could verify that it now works for you
Flags: needinfo?(jyavenard)
(Reporter)

Comment 17

2 years ago
I verified that the seek pauses are much shorter, less than one second, in today's Nightly.
status-firefox44: affected → fixed
https://hg.mozilla.org/mozilla-central/rev/7fc9c1614602
Status: NEW → RESOLVED
Last Resolved: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla44
(Assignee)

Comment 19

2 years ago
(In reply to Chris Peterson [:cpeterson] from comment #17)
> I verified that the seek pauses are much shorter, less than one second, in
> today's Nightly.

That's likely just a coincidence because the fix wouldn't have made nightly yet. 

You likely have all the files fully in the cache as you've played them before. Try flushing the data cache first
(In reply to Jean-Yves Avenard [:jya] from comment #11)
> Eugene, seeking is still quite slow even with the new MP3Demuxer ; 
> 
> seeking is done by decoding all frames until we've counted the right amount
> in MP3TrackDemuxer::ScanUntil
> 
> FastSeek only appears to be used for seeking backward. Why is that ?
> Can't there be a faster way, like simply guessing the bitrate?
> 
> Both Safari and Chrome seeks instantly on those mp3; but it can take up over
> 10s with firefox.

We can seek CBR files efficiently and safe using FastSeek, but we don't do special handling for CBR files because VBR files are dominant on the web.

For VBR files we can not reasonably estimate the bitrate for future time frames.
Using FastSeek for forward jumps would be unreliable and introduce unwanted side-effects like an increase of the total duration time or premature playback stopping (before total duration time is reached).
Using FastSeek for backward jumps isn't accurate but has less chance to introduce noticeable side-effects.

There are multiple ways to improve seeking performance like taking VBR headers' TOC into account, alternating scan/jump sequences and constructing a seek table, the latter being the most reliable way of doing it, I think. I'm planning to start working on this in bug 1163667, so I'm open for suggestions.
Flags: needinfo?(esawin)
Jean-Yves, are you planning to request an uplift to 42? Or you are ok if 42 ships with it?
Flags: needinfo?(jyavenard)
(Assignee)

Comment 22

2 years ago
Comment on attachment 8667122 [details] [diff] [review]
[mp3] Don't parse data we've already parsed.

Approval Request Comment
[Feature/regressing bug #]:1175768
[User impact if declined]: excessively long seek times, playback stalling
[Describe test coverage new/current, TreeHerder]: in nightly for several days
[Risks and why]: low. This is for MP3 playback only. 
[String/UUID change made/needed]: none
Flags: needinfo?(jyavenard)
Attachment #8667122 - Flags: approval-mozilla-beta?
Attachment #8667122 - Flags: approval-mozilla-aurora?
(Assignee)

Comment 23

2 years ago
Patches would likely need rebasing
Comment on attachment 8667122 [details] [diff] [review]
[mp3] Don't parse data we've already parsed.

Fix a regression, taking it.
Should be in 42 beta 6.
Attachment #8667122 - Flags: approval-mozilla-beta?
Attachment #8667122 - Flags: approval-mozilla-beta+
Attachment #8667122 - Flags: approval-mozilla-aurora?
Attachment #8667122 - Flags: approval-mozilla-aurora+
https://hg.mozilla.org/releases/mozilla-aurora/rev/a3080512e7a6
status-firefox43: affected → fixed
https://hg.mozilla.org/releases/mozilla-beta/rev/8974b3c15604 will be in beta 7
status-firefox42: affected → fixed
tracking-firefox42: ? → +
You need to log in before you can comment on or make changes to this bug.