Last Comment Bug 669556 - Video and audio stutters on lots of YouTube videos
: Video and audio stutters on lots of YouTube videos
Status: RESOLVED FIXED
:
Product: Core
Classification: Components
Component: Audio/Video (show other bugs)
: unspecified
: x86 Mac OS X
: -- normal (vote)
: mozilla10
Assigned To: Matthew Gregan [:kinetik]
:
Mentors:
: 641273 (view as bug list)
Depends on:
Blocks: 688363 cubeb
  Show dependency treegraph
 
Reported: 2011-07-05 23:05 PDT by Justin Dolske [:Dolske]
Modified: 2011-10-22 04:36 PDT (History)
6 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
debug log (2.12 MB, text/plain)
2011-09-06 00:13 PDT, Matthew Gregan [:kinetik]
no flags Details
patch v0 (7.06 KB, patch)
2011-10-02 19:37 PDT, Matthew Gregan [:kinetik]
cpearce: review+
christian: approval‑mozilla‑aurora-
Details | Diff | Splinter Review

Description Justin Dolske [:Dolske] 2011-07-05 23:05:45 PDT
I've been noticing this for probably a couple weeks now, and it's slowly dawned on me that it's more than just a bad connection. :(

I use the YouTube HTML5 player, and common problem goes something like this:

1) Load page, short delay for initial buffering
2) Video starts playing, everything fine. YT UI indicates media downloading is progressing just swell
3) Around 30-60 seconds later (or when buffering completes? not sure exactly) the flawless playback will suddenly start stuttering. It will play fine for < 5 seconds, then ooop-p-p-p-p-p-p-p-p-p-ps for 5-10 seconds, sometimes silence for a bit, and then repeat. The video appears frozen during this.
4) Oddly, if I click to seek to another part of the video (it's 100% buffered, so doesn't matter where) playback will continue smoothly from that point.

I think this is happening on the majority of videos I watch. I just reproduced it on this one for sure, lest it be media-specific.

http://www.youtube.com/watch?v=7CLfNIZ4LNo

I was able to reproduce this in a debug bug recently, but didn't see anything interesting in the console output when it happened.
Comment 1 Matthew Gregan [:kinetik] 2011-07-06 00:49:53 PDT
What version of OS X are you running, and on what hardware?  Is CPU% unusually high or low when the audio is stuttering?
Comment 2 Justin Dolske [:Dolske] 2011-07-08 13:06:06 PDT
I'm running the latest OS X version (10.6.8), on a new Macbook Pro from earlier in the year (2.3 Ghz i7 Sandy Bridge, 8GB).

I haven't noticed any particular CPU usage, but I reproduced while watching the output from top... When stuttering CPU usage for firefox was about 20%, when playing normally it was about 40%. the system and browser were otherwise fairly idle-seeming (I do have other tabs open).
Comment 3 Matthew Gregan [:kinetik] 2011-09-04 23:45:31 PDT
I'm having some luck reproducing this using: http://www.youtube.com/watch?v=btViXvIDsi0

It seems to be easier to reproduce in nightlies than in a local debug build, but it is possible to reproduce in a debug build given enough attempts.  I don't have much insight into the problem yet, but I have confirmed that we're underrunning and writing silence to the audio hardware in sydney_audio_mac.c's audio_callback.  When this happens, the audio thread is sleeping in Wait(AMPLE_AUDIO_USECS / 2), the audio queue has very little decoded audio in it, and the video queue is full (10 frames).
Comment 4 Matthew Gregan [:kinetik] 2011-09-06 00:13:49 PDT
Created attachment 558412 [details]
debug log
Comment 5 Matthew Gregan [:kinetik] 2011-09-06 00:18:30 PDT
The calculation to estimate how much audio data sydneyaudio has buffered relies on mCurrentFrameTime advancing, which only happens as AdvanceFrame is called.  If AdvanceFrame schedules itself to run far in the future (e.g. after skipToNextKeyFrame, with keyframes further apart than the ample audio threshold), a situation may arise where the state machine is estimating that sydneyaudio has plenty of audio data while sydneyaudio runs low on data.

What I'm seeing is:
- Hit skipToNextKeyFrame due to videoQueue becoming empty.
- Also have less than ample audio.
- As audio is decoded, the audio thread immediately queues it, so the queue remains near empty.
- Exit skipToNextKeyFrame, audio queue is near empty but mAudioEndTime - mCurrentFrameTime
  buffer estimation indicates that sydneyaudio has ample audio.
- AdvanceFrame schedules itself for 2869ms in the future.  mCurrentFrameTime won't update until
  next AdvanceFrame.
- DecodeLoop waits now that queues are full and ample audio is buffered.

At this point, DecodeLoop is waiting on the queues/buffered to run low.  AudioLoop is waiting for 500ms since there is ample audio buffered.  AdvanceFrame is not due to run for over 2.8s.  sydneyaudio's internal buffers run dry and underruns.

When AdvanceFrame finally runs, mCurrentFrameTime will be updating, causing the audio buffer estimation to switch from ample to low and causing another round of skipToNextKeyFrame.
Comment 6 Matthew Gregan [:kinetik] 2011-09-06 20:37:18 PDT
This becomes trivial to reproduce if skipToNextKeyFrame is unconditionally set to true in DecodeLoop.

We're not hitting this on Linux or Windows because sydneyaudio's buffer sizes are ~500ms and ~1000ms (respectively) and because they have minimum write sizes greater than one frame (which makes the chance of AudioLoop sleeping in |WAIT(AMPLE_AUDIO_USECS / 2)| much less likely).

It is possible to reproduce this on Linux with a 1000ms buffer and minWriteSamples forced to 1.  Conversely, forcing a 4k minimum write size for OS X allows the audio to play without underruns while skipping keyframes.
Comment 7 Matthew Gregan [:kinetik] 2011-09-06 22:51:30 PDT
This needs to be fixed before the new audio backend (bug 623444) is enabled, because that always returns a minimum write size of one frame and will buffer equal or more than the ample audio threshold, which means that we'll start suffering from this bug on all platforms.
Comment 8 Matthew Gregan [:kinetik] 2011-09-06 22:51:47 PDT
*** Bug 641273 has been marked as a duplicate of this bug. ***
Comment 9 Matthew Gregan [:kinetik] 2011-09-08 20:11:39 PDT
Bug 562840 comment 2 explains why the |WAIT(AMPLE_AUDIO_USECS / 2)| code was added:

(note that the times are now 1000ms and 500ms due to later changes to the buffering logic)

(In reply to Chris Pearce (:cpearce) (Mozilla Corporation) from comment #2)
> * If the audio push thread has more than 2000ms of audio queued ahead of the
> current playback position, sleep for 1000ms. Why? If we have lots of queued
> audio, the decode thread will sleep indefinitely, expecting to be woken up
> when the audio push thread pops off the audio queue. But if the audio queue
> is empty, the audio thread will also sleep indefinitely. This can happen
> when the audio thread has the just pushed the last packet, which isn't
> marked EOS (technically an invalid stream, likely an oggz-chopped file).
> This sleep I added works around this, coupled with a few NotifyAll()s in
> appropriate places.

If I understand correctly, this is describing a scenario where we have ample audio and where the audio queue is empty, meaning that the audio in sydneyaudio's buffers.  That describes a the same scenario as this bug, where the wait is making the problem worse.  It may be that the workaround is no longer necessary due to later fixes.

Removing the wait, the audio thread no longer bases its refill decisions on the (possibly incorrect) ample audio estimate.  Unfortunately, removing the wait also causes the "hit audio event queue max" limit to be reached constantly during normal playback if the platform's sydneyaudio buffers allow more than 100 AudioData buffers to be submitted in a short time.

I'll leave fixing the audio buffer fullness estimation to another bug.  We'd need to expose new APIs from sydneyaudio for this, I think, so it may be more worthwhile to get bug 623444 and related fixes done instead.

For this bug, I'll remove the wait and solve the "hit audio event queue max" problem.
Comment 10 Matthew Gregan [:kinetik] 2011-10-02 19:37:27 PDT
Created attachment 564107 [details] [diff] [review]
patch v0

Remove the Wait() so that audio refill is not dependent on inaccurately estimated buffer fullness.  This change also reduces behavioural differences between platforms, as the Wait() code was not hit often on Linux and Win32 due to minWriteFrames.

Avoid hitting the 100 event limit in nsAudioAvailableEventManager by limiting sydney_audio_mac.c's buffer size to 1000ms.  This also brings the code in line with the buffer sizing behaviour of Win32 (i.e. buffer is 1000ms calculated from sample rate, rather than simply using a 1.7MB buffer).

Untested locally since I have no Mac.  Try server is green so far: https://tbpl.mozilla.org/?tree=Try&rev=74cfbf0e80c2

dolske, if you could test the builds once they appear at http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/mgregan@mozilla.com-74cfbf0e80c2/ and confirm that this solves you problem, that'd be most excellent.
Comment 11 Justin Dolske [:Dolske] 2011-10-04 17:05:59 PDT
(In reply to Matthew Gregan [:kinetik] from comment #10)

> dolske, if you could test the builds once they appear 

Great success!

With a new profile, YouTube HTML5 trial enabled, and http://youtu.be/QH2-TGUlwu4...

On the current OS X nightly the video loads quickly and plays fine until 20-30 seconds in, at which point the audio goes crazy and the video freezes for seconds at a time.

With your test build, the whole 3:36 long video plays fine with no audio glitches. Yeah, I listened to the whole thing. :)
Comment 12 Matthew Gregan [:kinetik] 2011-10-10 17:53:44 PDT
https://hg.mozilla.org/integration/mozilla-inbound/rev/b773a00c239b
Comment 13 Justin Dolske [:Dolske] 2011-10-10 21:33:51 PDT
Would this be safe to take on Aurora too? I don't know how common this problems is outside of YouTube + OSX, but even just that's a lot of usage.
Comment 14 Matthew Gregan [:kinetik] 2011-10-10 23:15:36 PDT
It should be fairly safe, as this is bringing the behaviour closer to that of the other platforms.  I'll request approval for aurora once the patch has had a couple of days on the nightly channel.
Comment 15 Marco Bonardo [::mak] 2011-10-11 02:39:39 PDT
https://hg.mozilla.org/mozilla-central/rev/b773a00c239b
Comment 16 Matthew Gregan [:kinetik] 2011-10-11 19:02:33 PDT
Comment on attachment 564107 [details] [diff] [review]
patch v0

This breaks video playback badly on OS X if decode-time frame skipping kicks in.  Part of the change is extremely safe, as Win32 and Linux were already skipping this code most of the time.  The other part of the change is fairly straight-forward and aligns the behaviour more closely with Linux and Win32, so the chance of introducing new issues is fairly low.
Comment 17 christian 2011-10-13 14:28:30 PDT
Comment on attachment 564107 [details] [diff] [review]
patch v0

This looks like a problem that has existed since 4.0 release. We'll let this come up through the normal process.

Note You need to log in before you can comment on or make changes to this bug.