Prolonged delay resuming video playback after pausing with some videos

RESOLVED FIXED

Status

()

RESOLVED FIXED
9 years ago
9 years ago

People

(Reporter: kinetik, Assigned: kinetik)

Tracking

Trunk
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(status1.9.2 ?)

Details

(Whiteboard: [evang-wanted])

Attachments

(4 attachments, 3 obsolete attachments)

(Assignee)

Description

9 years ago
I have a somewhat badly constructed (produced by test video in which many of the "frames" do not have audio data associated with them that has revealed a couple of problems:

1. There can be drift between the audio clock and the wall clock.  The loop in PlayFrame() that waits for the current frame time to pass can alternate between using the wall clock and the audio clock in cases where some frames don't have audio data attached.

2. There's a problem resetting the wall clock/pause duration times when resuming from pause that causes a permanent drift and large amount of frame skipping the first time we enter PlayFrame() with a audioless frame.

No URL for the test video because the online copy has since been reencoded by the owner.

This problem *may* explain the issues seen in bug 520100, and possibly also in bug 498564.

I have a patch but it needs cleaning up and testing before I post it.

Comment 1

9 years ago
That certainly is a problematic little bit of code.  I look forward to seeing (and testing) your patch.
(Assignee)

Comment 2

9 years ago
It's definitely not related to bug 520100, but I have a theory about that one now.
(Assignee)

Comment 3

9 years ago
Created attachment 414159 [details] [diff] [review]
potential fix

This is the approach I've taken for the fix.  This patch isn't quite right, as I'm seeing a test failure (timeout) for one file in test_playback.html.
(Assignee)

Comment 4

9 years ago
test_playback.html times out on bug520493.ogg because the ended event never fires.  This is caused by the new PausePlayback() call I added to the QueueDecodedFrames wait loop.

When the audio stream is paused at this point, the audio playback thread is destroyed.  There's still 7330 bytes of audio buffered in sydneyaudio to play, so when we eventually make it to COMPLETED state, sa_stream_drain hangs waiting for the audio thread to play back the remaining buffered audio, which never happens.

sa_stream_drain should return an error if the caller tries to drain the stream when the audio backend is paused.
Duplicate of this bug: 541651
OS: Mac OS X → All
Hardware: x86 → All
(Assignee)

Comment 6

9 years ago
Bug 526411 comment 50 points to a public testcase for this problem.
(Assignee)

Comment 7

9 years ago
Created attachment 425386 [details] [diff] [review]
patch part 1 v0

Make sa_stream_drain return an error if the stream is not playing when drain is called.
Attachment #414159 - Attachment is obsolete: true
(Assignee)

Updated

9 years ago
Status: NEW → ASSIGNED
(Assignee)

Comment 8

9 years ago
Created attachment 425387 [details] [diff] [review]
patch part 2 v0

Don't clobber the system clock when resuming from pause.  Pause playback when waiting on the decode thread to avoid desynching the audio and system clocks.  Also removes some (now) bogus code from PausePlayback that could cause problems.
(Assignee)

Comment 9

9 years ago
Created attachment 425389 [details] [diff] [review]
patch part 3 v0

Periodically resync the system clock against the audio clock at a time when we're trusting the audio clock.  This reduces the drift between clocks fairly significantly so that poorly muxed files (such as those where half of the "frames" don't have audio attached) play back smoothly.  Without this change, these poorly muxed files suffer from frame dropping due to clock drift.

This change is kinda gross, but a cleaner fix requires more work done in libsydneyaudio, which I'm saving for a later date.  The current plan here is to have the sound backend report the current playback position via callbacks and use that data interpolated with the system clock to provide a continuously updating master clock on all platforms.
Whiteboard: [evang-wanted]
(Assignee)

Updated

9 years ago
Attachment #425386 - Flags: review?(chris.double)
(Assignee)

Updated

9 years ago
Attachment #425387 - Flags: review?(chris.double)
(Assignee)

Updated

9 years ago
Attachment #425389 - Flags: review?(chris.double)

Updated

9 years ago
Attachment #425386 - Flags: review?(chris.double) → review+

Updated

9 years ago
Attachment #425387 - Flags: review?(chris.double) → review+

Updated

9 years ago
Attachment #425389 - Flags: review?(chris.double) → review+
(Assignee)

Comment 10

9 years ago
http://hg.mozilla.org/mozilla-central/rev/b876c36242dc
http://hg.mozilla.org/mozilla-central/rev/9b33c91c851d
http://hg.mozilla.org/mozilla-central/rev/d7a32460bb32
Status: ASSIGNED → RESOLVED
Last Resolved: 9 years ago
status1.9.2: --- → ?
Resolution: --- → FIXED
(Assignee)

Comment 11

9 years ago
test_bug468190.html went orange on Windows and test_ended2.html went orange on Linux.  This made it through tryserver and local tests on multiple platforms.  I've backed the patches out for now.

http://hg.mozilla.org/mozilla-central/rev/5988d1cd74ff
http://hg.mozilla.org/mozilla-central/rev/0d981e2a7a25
http://hg.mozilla.org/mozilla-central/rev/1f8d93376db0

This'll be a good candidate for the Sword +5 Against Orange.
(Assignee)

Updated

9 years ago
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
(Assignee)

Comment 13

9 years ago
It looks like this could be caused by the PausePlayback() call I added in patch #2 when we're about to start buffer-waiting.
(Assignee)

Comment 14

9 years ago
The Start/StopPlayback clock handling for videos with no audio is totally broken with this patch.  New patch coming shortly.
(Assignee)

Comment 15

9 years ago
Looks like the fix for that solved failures in test_bug468190 on the Windows tryserver but not test_ended2 on the Linux builds.
(Assignee)

Comment 16

9 years ago
It doesn't actually fix it, must have been a spurious pass.  Still investigating.
(Assignee)

Comment 17

9 years ago
There's a race in QueueDecodedFrames that seems to be the cause of this (and probably the random orange in the same tests we've seen before this patch made it so obvious).

The problem is here:
http://mxr.mozilla.org/mozilla-central/source/content/media/ogg/nsOggDecoder.cpp#1158

We queue the update event before we add the frame we're notifying about.  This means that the main thread update can run before the frame is actually added, and thus see a different state to the one we're trying to signal.

Changing the ordering of the frame push and event firing isn't sufficient to solve this, as it's also possible to fire the event and then immediately revert to the previous state, which means the main thread never sees the state that we were attempting to notify it about.  The fix for this is to specify the state we're notifying about as part of the event.  I tried this during an earlier tryserver build but missed the push vs update race in QueueDecodedFrames, so my changes effectively ensured that the wrong state would *always* be reported in the racing case.

I've pushed two runs of the new patch to tryserver and both passed the relevant tests.
(Assignee)

Comment 18

9 years ago
Created attachment 432468 [details] [diff] [review]
patch part 2 v1

Revised part 2 to fix start/stop with videos that have no sound.  The last frame number is reset in StopPlayback so it's necessary to reset the system clock too.
Attachment #425387 - Attachment is obsolete: true
Attachment #432468 - Flags: review?(chris.double)
(Assignee)

Comment 19

9 years ago
Created attachment 432469 [details] [diff] [review]
patch part 4 v0

Make ready state transitions initiated by the decode thread more reliable by including the new state in the event.  Fixes an ABA problem where we could play through without ever moving beyond HAVE_CURRENT_DATA.

This fixes a race where we would fire UpdateReadyStateForData to signal that we've got frames queued (i.e. we can move beyond HAVE_CURRENT_DATA) but by the time the main thread processed the event we've thrown the queue frames away (e.g. due to frame skipping).  The patch ensures that we handle the event based on the state at the time it was raised.  In the case described above we'll immediately revert to HAVE_CURRENT_DATA because another event will be queued that signals we've emptied the frame queue.

I believe the new behaviour makes sense because being able to play through an entire file without ever moving beyond HAVE_CURRENT_DATA should be impossible.
Attachment #432469 - Flags: review?(chris.double)
(Assignee)

Updated

9 years ago
Blocks: 498955
(Assignee)

Updated

9 years ago
Blocks: 492894
(Assignee)

Comment 20

9 years ago
Part 4 probably fixes the random orange in bugs 492894 and 498955.

Updated

9 years ago
Attachment #432468 - Flags: review?(chris.double) → review+

Comment 21

9 years ago
Comment on attachment 432469 [details] [diff] [review]
patch part 4 v0

>+  // entered.  Main thread only.
>+  void NextFrameUnavailableBuffering();
>+  void NextFrameAvailable();
>+  void NextFrameUnavailable();

In the implementation for these please assert that they are called only on the main thread.

r+ with that.
Attachment #432469 - Flags: review?(chris.double) → review+
(Assignee)

Comment 22

9 years ago
Created attachment 432478 [details] [diff] [review]
patch part 4 v1

Add main thread assertions.  Review carried forward.
Attachment #432469 - Attachment is obsolete: true
Attachment #432478 - Flags: review+
You need to log in before you can comment on or make changes to this bug.