Closed Bug 1131487 Opened 10 years ago Closed 10 years ago

DASH sample stalls

Categories

(Core :: Audio/Video, defect)

x86_64
macOS
defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla38
Tracking Status
firefox37 --- fixed
firefox38 --- fixed

People

(Reporter: reinhard.grandl, Assigned: jya)

References

(Depends on 1 open bug, )

Details

Attachments

(3 files, 1 obsolete file)

User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/40.0.2214.111 Safari/537.36 Steps to reproduce: Open the URL http://www.dash-player.com/demo/streaming-server-and-encoder-support/?mpd=http%3A%2F%2Fbitcdn-global.bitmovin.com%2Fcontent%2Fsintel%2Fsintel.mpd with Firefox 36.0 Actual results: The streams starts playing, but video stalls after a few seconds (you might don't see it clearly, because there is a fade from black) - audio continues playing. The buffer for video does not run try and no error message is generated. Expected results: The stream (audio and video) plays without stalls.
Component: Untriaged → General
Depends on: MSE
Hardware: x86 → x86_64
that the start time is <= 0 isn't what is stalling the video. That's not the reason. I only had a quick glance, but appendBuffer was called with video from 0 to 30s, and then it jumps to providing video to 600s+.. This is never going to play, as there's no data to play.. stalling video is the proper behaviour under those circumstances. Now there may be an error on our side that would cause the cts to be improperly calculated... we'll see
Summary: Fragmented MP4 stalls video with start time not equal to zero → DASH sample stalls
Ok, I just added another stream with start time not equal to zero, but this time with a positive offset (as it might be helpful for testing) - http://www.dash-player.com/demo/streaming-server-and-encoder-support/?mpd=http%3A%2F%2Fgce-bitbucket.storage.googleapis.com%2FbitStorage%2F2_6f9d0adade5b9d4547d0ac6ae436ae9c%2F546_Sintel.2010.720p.mkv%2Fmpds%2FSintel.2010.720p.mkv.mpd The behaviour is similar, although the video keeps playing for 10 seconds now. Are you getting the information which time span is added to the buffer from the about:media view? If so, how to read it?
Hmm.. this time the behaviour is different. It seems to vary (this is the SegmentTemplate one, first one) Internal Data: Dumping data for reader 143581c00: Dumping Audio Track Decoders: - mLastAudioTime: 31.231999 Reader 1: 1369c2800 ranges=[(-0.021333, 73.386666)] active=true size=1196881 Reader 0: 1369de800 ranges=[(-0.021333, 1.962666)] active=false size=33090 Dumping Video Track Decoders - mLastVideoTime: 68.000000 Reader 12: 12e00e000 ranges=[(68.000000, 70.000000)] active=true size=28442 Reader 11: 12e008000 ranges=[(66.000000, 68.000000)] active=false size=52767 Reader 10: 12e006000 ranges=[(64.000000, 66.000000)] active=false size=28593 Reader 9: 12dc2d800 ranges=[(62.000000, 64.000000)] active=false size=69212 Reader 8: 121424000 ranges=[(60.000000, 62.000000)] active=false size=58889 Reader 7: 11d730800 ranges=[(58.000000, 60.000000)] active=false size=46096 Reader 6: 12e019000 ranges=[(56.000000, 58.000000)] active=false size=61976 Reader 5: 12a9d1800 ranges=[(54.000000, 56.000000)] active=false size=67301 Reader 4: 12db77800 ranges=[(52.000000, 54.000000)] active=false size=80228 Reader 3: 12e00b800 ranges=[(50.000000, 52.000000)] active=false size=79665 Reader 2: 12dc45800 ranges=[(48.000000, 50.000000)] active=false size=955954 Reader 1: 120ec4000 ranges=[(46.000000, 48.000000)] active=false size=976964 Reader 0: 120c8e800 ranges=[(44.000000, 46.000000)] active=false size=544393 So here it shows that our current playback position is at 30s exactly. but we have data to play only from 44s onward (up to 70s). The "active" reader is the one we last added data to. I'm also puzzled on why we would have that many decoders. Are you using sourceBuffer.timestampOffset attribute or feeding the fragments out of order? Did you call remove on the source buffer? I have on my debug machine an eviction threshold pretty low (3MB) but this shouldn't explain what's happening here.
Component: General → Web Audio
Product: Firefox → Core
Version: 36 Branch → Trunk
Component: Web Audio → Video/Audio
oh, do you send the init segment before each media segment?
We are not using .timestampOffset. To add a segment to the buffer we are using .addSourceBuffer, with segments in order. At startup and at every representation switch we send an init segment, but not before every media segment. During the stream is playing we are not removing anything from the buffer manually. The behaviour I experience is a little different, as I do not get a missing time span, although they are overlapping: mediasource:http://www.dash-player.com/76e85ab8-f0d4-0442-b575-d48812a666a0 currentTime: 30.302041 SourceBuffer 0 start=0.083333 end=52.041666 start=52.083333 end=74.083333 SourceBuffer 1 start=0 end=81.472 Internal Data: Dumping data for reader 13ce3d000: Dumping Audio Track Decoders: - mLastAudioTime: 31.359999 Reader 0: 11e73e800 ranges=[(0.000000, 81.472000)] active=true size=1294163 Dumping Video Track Decoders - mLastVideoTime: 10.458333 Reader 4: 13dcd3800 ranges=[(52.083333, 74.083333)] active=false size=9370391 Reader 3: 1247d1000 ranges=[(41.666666, 52.041666)] active=false size=4673993 Reader 2: 11d841000 ranges=[(20.875000, 41.708333)] active=false size=3843254 Reader 1: 12bf15000 ranges=[(10.458333, 20.875000)] active=true size=605949 Reader 0: 11e734000 ranges=[(0.083333, 10.500000)] active=false size=3171844
Correction: we are of course using .appendBuffer to add segments.
(In reply to Reinhard from comment #5) > We are not using .timestampOffset. To add a segment to the buffer we are > using .addSourceBuffer, with segments in order. At startup and at every ?? you mean appendBuffer right? We have a limitation of 16 (an arbitrary number) source buffers. > representation switch we send an init segment, but not before every media > segment. During the stream is playing we are not removing anything from the > buffer manually. > > The behaviour I experience is a little different, as I do not get a missing > time span, although they are overlapping: some are overlapping, some are discontinuous.. Over 0.04s gap between segments. that video can't play, it's invalid at 52.04s. We have a leeway for switching to the next frame, but you have big gap in your video here. Now there could be a bug, it seems stuck at 10.458333s. Did you try with Nightly? > Reader 4: 13dcd3800 ranges=[(52.083333, 74.083333)] active=false > size=9370391 > Reader 3: 1247d1000 ranges=[(41.666666, 52.041666)] active=false > size=4673993 > Reader 2: 11d841000 ranges=[(20.875000, 41.708333)] active=false > size=3843254 > Reader 1: 12bf15000 ranges=[(10.458333, 20.875000)] active=true > size=605949 > Reader 0: 11e734000 ranges=[(0.083333, 10.500000)] active=false > size=3171844 I haven't looked into the details to be honest, I'm finishing something else. #media on the Mozilla IRC channel will be better to talk about this. my nick is jya
With Nighlty everything seems to work fine - no stalls. The stream is playing smooth, audio as well as video. Also the gap at 52.04s does not influence the behaviour. Is there a way to access some debug output like about:media also in the Nightly? We can also talk via IRC channel.
Fix timestamp calculations when start time aren't 0.
Attachment #8562046 - Flags: review?(matt.woodrow)
Assignee: nobody → jyavenard
Status: UNCONFIRMED → ASSIGNED
Ever confirmed: true
(In reply to Reinhard from comment #8) > With Nighlty everything seems to work fine - no stalls. The stream is > playing smooth, audio as well as video. Also the gap at 52.04s does not > influence the behaviour. Is there a way to access some debug output like > about:media also in the Nightly? > > We can also talk via IRC channel. Good to know.. Nightly tomorrow will be broken :( lucky you reported that video! Sorry for not seeing the problem earlier, the reported timestamps were incorrect. about:media works in nightly, you need to install a plugin: https://github.com/gavinsharp/aboutmedia
Adjust negative start time near 0 to 0.
Attachment #8562069 - Flags: review?(matt.woodrow)
Attachment #8562046 - Flags: review?(matt.woodrow) → review-
Attachment #8562046 - Flags: review- → review+
Attachment #8562069 - Flags: review?(matt.woodrow) → review+
That video still stall around 50s-ish due to discontinuity... We should handle such discontinuity and skip over it rather than treat it as not having enough data
Depends on: 1131919
Keywords: leave-open
Blocks: MSE
No longer depends on: MSE
Hi. Ok.. I've found out why this stall, and for once it's not us :) This DASH player feeds data continuously, without ever stopping. This is not good to start with. We have a 75MB buffer limit, at which time data will be evicted so memory usage stays within that memory constraint. On this playback instance, playback stalled at 158s. Looking in the logs you can see that at some stage the segment [158,168] has been evicted. That data is never re-submitted. It is up to the DASH player to check the buffered range and ensure that the player has enough data to play and reload if necessary. This happens during the Prepare Append algorithm and is synchronous. So as soon as you've called appendBuffer; you should check the sourcebuffer buffered range and see what has been evicted (per spec: Implementations may use different methods for selecting removal ranges so web applications should not depend on a specific behavior. The web application can use the buffered attribute to observe whether portions of the buffered data have been evicted.) Also, ideally you shouldn't feed data continuously like that, we're talking MB in RAM here. It fed the entire 15 minutes @ 1080p. Youtube for example only buffered the entire video if the bitrate is low enough and ensure that it won't exceed the 75MB buffer. Otherwise they only feed about 20s ahead of the current playback position. Also when changing resolution, you could use sourcebuffer.remove to remove the old lower-res, so if the user were to seek backward they would get the new resolution content rather than get back to the old one.
Flags: needinfo?(reinhard.grandl)
No longer blocks: MSE, 1131482, 1131952
Depends on: 1131482, 1131952
No longer depends on: 1131919
Keywords: leave-open
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla38
Hi, Thanks for your effort! I'm not sure this is really the reason for this issue, though. Our player tries to maintain a constant buffer level, usually 40 seconds although this can be configured. I tried with 10 seconds buffer and it still has the same behavior - the video starts stalling at about 10 seconds of playback and returns at about 20 seconds and plays the rest of the video perfectly. Also, if I manually select a single quality (even it's the highest) before starting playback, the video plays through without any problems. So maybe there is a problem when switching qualities? We do bitrate as well as resolution switching. Until the stall occured (second 10), we have pushed about 10.3 MB (for both, audio and video combined) into the buffer, so we are far from the 75MB buffer limit at this point. Also the about:media says for me that everything should be there: http://www.dash-player.com/release-test/?mpd=http%253A%252F%252Fgce-bitbucket.storage.googleapis.com%252FbitStorage%252F2_6f9d0adade5b9d4547d0ac6ae436ae9c%252F546_Sintel.2010.720p.mkv%252Fmpds%252FSintel.2010.720p.mkv.mpd mediasource:http://www.dash-player.com/2e393b07-b351-41b3-92bd-d976adec5cfa currentTime: 10.5 SourceBuffer 0 start=0.083333 end=52.083333 SourceBuffer 1 start=0 end=52.053333 Internal Data: Dumping data for reader 10be1c30: Dumping Audio Track Decoders: - mLastAudioTime: 12,159999 Reader 0: 2534d000 ranges=[(0,000000, 52,053333)] active=true size=827004 Dumping Video Track Decoders - mLastVideoTime: 21,291667 Reader 3: 254cb800 ranges=[] active=false size=794 Reader 2: 21b23000 ranges=[(20,875000, 52,083333)] active=true size=5825200 Reader 1: 1d447c00 ranges=[(10,458333, 20,875000)] active=false size=605949 Reader 0: 2534b400 ranges=[(0,083333, 10,500000)] active=false size=3171844 I have noticed that the range of Reader 0 overlaps with the range of Reader 1 - and that's were (at least for me) the error occurs. You are right, in continuous playback (i.e. without seeking) we do not re-submit data as it has never been necessary. We probably should observe the buffer better... But wouldn't it be better to remove old, already played data instead of future data? ;) We probably will use sourcebuffer.remove to enhance our preferred behavior. At the moment, we do not delete any data as the MediaSource does usually a good job. In the Firefox Nightly (38.01a 2014-02-10) the stream works like a charm!
(In reply to daniel.weinberger from comment #16) > Hi, > > Thanks for your effort! > > I'm not sure this is really the reason for this issue, though. Your about:media shows a different condition than what I experienced. For me it my various attempts it stalled because data got evicted, not because there was overlap in segments. There may be a problem in switching, that's definitely possible. When selecting which sample to play, we select the last one added as we assume it will have the best quality. > > Our player tries to maintain a constant buffer level, usually 40 seconds > although this can be configured. I tried with 10 seconds buffer and it still > has the same behavior - the video starts stalling at about 10 seconds of > playback and returns at about 20 seconds and plays the rest of the video > perfectly. That's not what I'm experiencing.. I never see the rate of the appendBuffer calls slowing down, it just keep feeding new data. > > Also, if I manually select a single quality (even it's the highest) before > starting playback, the video plays through without any problems. So maybe > there is a problem when switching qualities? We do bitrate as well as > resolution switching. There could be an issue when switching resolution if there's an overlap in timestamp. That stream isn't per spec anyway as two segments for the same content do not always have the same time range. But we should handle that better regardless. > > Until the stall occured (second 10), we have pushed about 10.3 MB (for both, > audio and video combined) into the buffer, so we are far from the 75MB > buffer limit at this point. Also the about:media says for me that everything > should be there: > > http://www.dash-player.com/release-test/?mpd=http%253A%252F%252Fgce- > bitbucket.storage.googleapis. > com%252FbitStorage%252F2_6f9d0adade5b9d4547d0ac6ae436ae9c%252F546_Sintel. > 2010.720p.mkv%252Fmpds%252FSintel.2010.720p.mkv.mpd > mediasource:http://www.dash-player.com/2e393b07-b351-41b3-92bd-d976adec5cfa > currentTime: 10.5 > SourceBuffer 0 > start=0.083333 end=52.083333 > SourceBuffer 1 > start=0 end=52.053333 > Internal Data: > Dumping data for reader 10be1c30: > Dumping Audio Track Decoders: - mLastAudioTime: 12,159999 > Reader 0: 2534d000 ranges=[(0,000000, 52,053333)] active=true size=827004 > Dumping Video Track Decoders - mLastVideoTime: 21,291667 > Reader 3: 254cb800 ranges=[] active=false size=794 > Reader 2: 21b23000 ranges=[(20,875000, 52,083333)] active=true > size=5825200 > Reader 1: 1d447c00 ranges=[(10,458333, 20,875000)] active=false > size=605949 > Reader 0: 2534b400 ranges=[(0,083333, 10,500000)] active=false > size=3171844 That's interesting. I have an idea on what could be happening here. What's bizarre is that you're at 10.5s yet the current active reader doesn't have the time required. > > I have noticed that the range of Reader 0 overlaps with the range of Reader > 1 - and that's were (at least for me) the error occurs. > > You are right, in continuous playback (i.e. without seeking) we do not > re-submit data as it has never been necessary. We probably should observe > the buffer better... > But wouldn't it be better to remove old, already played data instead of > future data? ;) We probably will use sourcebuffer.remove to enhance our Oh, we do remove in priority past data. It's the first thing to go. But in my case, I was at 150s play position, it had buffered over 600s already and had reached the 75MB limit. It had evicted everything prior 130s. The only thing left to be dropped was future data. And it always remove the oldest data first Btw, you can change the buffer threshold if you want to stress your code, drop it to so,etching like 3MB. > preferred behavior. At the moment, we do not delete any data as the > MediaSource does usually a good job. > > In the Firefox Nightly (38.01a 2014-02-10) the stream works like a charm! Good to know, that will be all uplifted to 37.
There's still a stall occurring, trying to get to the bottom of it
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Daniel, the setting you can play with to force evicting data quicker is: media.mediasource.eviction_threshold , set it to 3145728 , it will cause to evict within 60s of buffered video.
Actually no. I only get the stall once we reach a point where the data got evicted and the DASH player doesn't resubmit those data. Issue is with the dash player. can open another bug if you see another problem. thank you for reporting it!
Status: REOPENED → RESOLVED
Closed: 10 years ago10 years ago
Resolution: --- → FIXED
Actually, of course as I said that I did reproduce that stall (13')
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Fix stall when changing decoders (usually happening when changing resolution). The buffered end time in those mp4 segments are made of a ratio that can't exactly be represented in IEEE 754 base 2 and are instead rounded, (like 287.45833300000004). When we attempt to skip to the next reader by adjusting the end time, 287.45833300000004 is rounded to 287.458333 (287458333us) which is always inferior to 287.45833300000004. So instead of switching to the next decoder, we select the same one, and we end up looping forever Seek -> Decode -> End of Stream Error -> Seek -> Decode. Add some logging.
Attachment #8563828 - Flags: review?(matt.woodrow)
mCurrentDecoder is the decoder we're currently adding data to; not the decoder currently playing. It is always the last decoder in the list of decoders. As such, we were always evicting all data from all decoders but the currently playing one. I split the loop in two as I felt it was clearer to understand. We proceed in three steps, each step can be aborted if we've already evicted more data than required. First step is to evict all past data from current playback position. Step 2: Evict all data from decoders anterior to the currently playing one, assuming we've already played from those (and in practice unless you seek a lot, it's always true) Step 3: We evict future data, starting from the furthest away, only keeping the currently playing reader and the next one we will be switching to once the current is done.
Attachment #8563901 - Flags: review?(cajbir.bugzilla)
Comment on attachment 8563901 [details] [diff] [review] Evict data we likely previously read and future data when possible Wrong bug number
Attachment #8563901 - Attachment is obsolete: true
Attachment #8563901 - Flags: review?(cajbir.bugzilla)
Comment on attachment 8563828 [details] [diff] [review] Part3. Fix stall when switching decoders Review of attachment 8563828 [details] [diff] [review]: ----------------------------------------------------------------- ::: dom/media/mediasource/MediaSourceReader.cpp @@ +210,5 @@ > aDecoder->GetBuffered(ranges); > if (ranges->Length() > 0) { > + // End time is a double so we convert to nearest greater by adding 1 > + // to ensure we are always slightly past it. > + int64_t end = ranges->GetEndTime() * USECS_PER_S + 1; Can't we just use ceil? @@ +232,5 @@ > // End of stream. Force switching past this stream to another reader by > // switching to the end of the buffered range. > MOZ_ASSERT(aReason == END_OF_STREAM); > if (mAudioSourceDecoder) { > + int64_t old = mLastAudioTime; Might want to make this #ifdef PR_LOGGING to avoid unused variable warnings if it isn't defined.
Attachment #8563828 - Flags: review?(matt.woodrow) → review+
With bug 1132796, we don't evict as quickly future data. This allows this particular video to play all the way to the end.
Depends on: 1132796
Status: REOPENED → RESOLVED
Closed: 10 years ago10 years ago
Resolution: --- → FIXED
Comment on attachment 8563828 [details] [diff] [review] Part3. Fix stall when switching decoders Requesting 37 uplift for all 3 patches on this bug. Approval Request Comment [Feature/regressing bug #]: MSE [User impact if declined]: Spec compliance, possible stalls playing MSE video. Less consistent testing and harder to port later changes. [Describe test coverage new/current, TreeHerder]: Landed on m-c. [Risks and why]: Changes are confined to MSE code, so regression risk is minimal. [String/UUID change made/needed]: None.
Attachment #8563828 - Flags: approval-mozilla-aurora?
Comment on attachment 8563828 [details] [diff] [review] Part3. Fix stall when switching decoders As noted, pre-approval was granted for a collection of MSE changes. Adding approval to the bug. Aurora+
Attachment #8563828 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Attachment #8562069 - Flags: approval-mozilla-aurora+
Attachment #8562046 - Flags: approval-mozilla-aurora+
Flags: needinfo?(reinhard.grandl)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: