1120550 - Video playback freezes while audio keeps going when seeking around near end of video

Status: RESOLVED FIXED

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

Description

[Bobby Holley (:bholley)]

This is happening to me with this morning's nightly (including my and mattwoodrow's recent patches). It happens reliably on the minecraft video (see URL). I seek near to the end of the stream, let it buffer to the end, and then start seeking backwards.

I think this is probably relating to us getting confused about what "EOS" means in the context of MSE. My guess is that we end up invoking VideoQueue().Finish(), and never manage to reset that.

I'm currently looking into the intermittent oranges triggered by bug 1119456. If someone else could have a look at this that would be great.

Comment 1

[Matt Woodrow (:mattwoodrow)]

Attachment: handle-eos

Bobby, can you reproduce this in local builds?

This patch fixes one possible cause, where we were treating endOfStream() as meaning *all* data was available, not just the last segment.

I think that could cause issues like you describe, and would be dependent on how quickly youtube loads data.

Comment 2

[Bobby Holley (:bholley)]

Comment on attachment 8547787 [details] [diff] [review]
handle-eos

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

So I managed to reproduce the issue reliably with a local opt build. The key seems to be to use my actual browsing profile.

This patch didn't fix the problem. As far as I can tell, it introduced a second failure mode, in which both audio and video stop, and the player ceases to respond to any seeks I perform by dragging the slider.

I took logs of each of the 3 failures, which I'll attach.

::: dom/media/mediasource/MediaSourceReader.cpp
@@ +464,5 @@
> +
> +  double maxEndTime = -1;
> +  nsRefPtr<MediaDecoderReader> lastReader;
> +
> +  for (int32_t i = 0; i < aTrackDecoders.Length(); i++) {

Nit: uint32_t to avoid a warning

Comment 3

[Bobby Holley (:bholley)]

Attachment: video-hang-audio-play-no-woodrowpatch.txt.zip

This is a clean build of trunk (aside from commenting out the excessive logging from unimplemented functions on SourceBufferResource). This is a log of the problem described in this bug.

Comment 4

[Bobby Holley (:bholley)]

Attachment: video-hang-audio-play-with-mattwoodrowpatch.txt.zip

This is the same bug, with matt's patch applied.

Comment 5

[Bobby Holley (:bholley)]

Attachment: video-hang-both-with-mattwoodrowpatch.txt.zip

This is the new failure mode introduced by matt's patch.

Comment 6

[Matt Woodrow (:mattwoodrow)]

You have WebM enabled in your browsing profile, don't you? :)

Comment 7

[Matt Woodrow (:mattwoodrow)]

Reduced first log to only show the bits relevant to the failure: http://pastebin.mozilla.org/8202022

Lines 5 - 12 show us seeking the video reader. We see the log message "Reader [13c062000] for Decoder [13f418830]: About to seek to 254.921577s". This comes from [1]

Lines 30-38 show us seeking the audio reader, see the MP4Reader log messages.

Both seeks appear to work fine, we seek to 254 seconds within a video reader covering (250.000000, 275.874000).

Then lines 63-76 show us requesting a video frame from that reader, and it returning EOS.

The remainder is us determining that we have no video readers after this one, and then propagating the EOS failure up to MDSM.

Seems like a bug with the WebM demuxer and seek isn't working for some reason.

I don't think this affects us when we only have mp4 tracks, so I'll remove it from the blocking list.

[1] http://mxr.mozilla.org/mozilla-central/source/dom/media/webm/WebMReader.cpp#974

Comment 8

[Matt Woodrow (:mattwoodrow)]

It's interesting that youtube is serving WebM video tracks with mp4 audio tracks, I didn't realize they did that.

Comment 9

[Ralph Giles (:rillian)]

(In reply to Matt Woodrow (:mattwoodrow) from comment #8)
> It's interesting that youtube is serving WebM video tracks with mp4 audio
> tracks, I didn't realize they did that.

IIRC they'll serve vorbis if the user-agent can't play AAC, but not otherwise. :/

Comment 10

[Bobby Holley (:bholley)]

(In reply to Matt Woodrow (:mattwoodrow) from comment #6)
> You have WebM enabled in your browsing profile, don't you? :)

Doh! Yeah, I just remembered that I'd turned it on not long before to check something. Sorry for not noticing and for the time wasted - my brain was kinda jelly yesterday.

Comment 11

[Jean-Yves Avenard [:jya]]

I think bug 1096089 (2nd patch) will fix this issue

Comment 12

[Anthony Jones (:ajones, :kentuckyfriedtakahe, :k17e)]

Bobby - That patch has landed, can we close this?

Comment 13

[Bobby Holley (:bholley)]

Need to retest at some point, but we determined that this was only happening with WebM, so we should ignore it for now.

Comment 14

[Jean-Yves Avenard [:jya]]

I can reproduce the issue after multiple seekings, while changing resolution before each seek (to force clearing the buffer).

From time to time, it will stall for a while and then audio plays while video is frozen

This doesn't happen just near the end however, so may be worth creating a new bug

Comment 15

[Jean-Yves Avenard [:jya]]

Attachment: logs-freeze.txt.zip

Here is the log with the problem occurring.

Log is long because I was debugging something else, and it just happened to occur.

Comment 16

[Jean-Yves Avenard [:jya]]

playback position at the time logs were taken was 1:59

Comment 17

[Jean-Yves Avenard [:jya]]

raising to P2 as I can reproduce the problem rather consistently

Comment 18

[Bobby Holley (:bholley)]

jya, can you explain this log a bit? It looks like the first 20% or so is just playing, then it seeks a few times, then it decodes for another 40% or so, then stays in seeking (?) for another 15%, then decodes until the end.

The long seek period is interesting (looks like the audio seeks much more quickly than the video, which needs to drop a lot of samples), but the audiosink does not appear to be playing during that time.

Comment 19

[Jean-Yves Avenard [:jya]]

What I do is this:

start playback, change resolution from 144p to 480p let play for a second or two, seek. change resolution from 480 to 144, let play for a second or two, seek backward, repeat.

At one stage the video hangs, and CPU usage gets high (likely the same issue as bug 1127203)
With bug 1125776's patches applied, however it becomes much more difficult to reproduce the issue. This would be explained with the race between a decoder showing up as available in the SourceBuffer::Buffered while not being yet initialized.

Comment 20

[Bobby Holley (:bholley)]

(In reply to Jean-Yves Avenard [:jya] from comment #19)
> What I do is this:
> 
> start playback, change resolution from 144p to 480p let play for a second or
> two, seek. change resolution from 480 to 144, let play for a second or two,
> seek backward, repeat.
> 
> At one stage the video hangs, and CPU usage gets high (likely the same issue
> as bug 1127203)
> With bug 1125776's patches applied, however it becomes much more difficult
> to reproduce the issue. This would be explained with the race between a
> decoder showing up as available in the SourceBuffer::Buffered while not
> being yet initialized.

Ok. Let's see if it still reproduces with those two fixes in.

Comment 21

[Jean-Yves Avenard [:jya]]

Unfortunately, while much harder to reproduce, it can still happen.

YouTube test 47. Seek (bug 1130263), exhibits that exact same behaviour sometimes while we have the data, things are stalled.

Interestingly, sometimes I had the opposite situation, video plays with no audio.

Comment 22

[Bobby Holley (:bholley)]

(In reply to Jean-Yves Avenard [:jya] from comment #21)
> Unfortunately, while much harder to reproduce, it can still happen.
> 
> YouTube test 47. Seek (bug 1130263), exhibits that exact same behaviour
> sometimes while we have the data, things are stalled.
> 
> Interestingly, sometimes I had the opposite situation, video plays with no
> audio.

Is this still the case even in the light of your comment yesterday that we're all green on YouTube tests?

If so, can you capture an updated log?

Comment 23

[Jean-Yves Avenard [:jya]]

(In reply to Bobby Holley (Busy with media, don't ask for DOM/JS/XPConnect things) from comment #22)
> (In reply to Jean-Yves Avenard [:jya] from comment #21)
> > Unfortunately, while much harder to reproduce, it can still happen.
> > 
> > YouTube test 47. Seek (bug 1130263), exhibits that exact same behaviour
> > sometimes while we have the data, things are stalled.
> > 
> > Interestingly, sometimes I had the opposite situation, video plays with no
> > audio.
> 
> Is this still the case even in the light of your comment yesterday that
> we're all green on YouTube tests?
> 
> If so, can you capture an updated log?

No, I think this problem has been fixed with bug 1125469

Now the only time we will have a stall is if we have a discontinuity, slightly larger than our fuzz factor. Will enter WAITING_FOR_DATA state and never come out of it.
But YouTube has perfectly continuous data so it's not a problem with YouTube.

I'll close this bug, and if it happens again we can re-open it