480477 - Ogg backend may not fire load event if stream loads very quickly

Status: RESOLVED WORKSFORME

(Core :: Audio/Video, defect)

Description

[Matthew Gregan [:kinetik]]

I'm seeing test timeouts with test_audio[12].html from bug 454971.  This is caused by the load event never firing due to a race.  The test file is small enough that it loads completely and calls ResourceLoaded (from OnStopRequest) while mPlayState is still LOADING.  This causes us to return early from ResourceLoaded before the load event is fired.

Comment 1

[Robert O'Callahan (:roc) (email my personal email if necessary)]

Is this still a problem?

Comment 2

[Matthew Gregan [:kinetik]]

I haven't seen it happen when running the tests from bug 454971 recently, so it seems to be less worse, at least.  I'll need to review the code to see if what I described can still happen.

Comment 3

[Matthew Gregan [:kinetik]]

Turned out this was a variation of the symptoms described in bug 461286.  I went back to the revision I reported this against (f79a0ec61e3d) since didn't think this could occur in the current code, but wanted to be sure I understood how it used to fail.

Going back to that revision and reproducing the problem, what's going on is:

1. The HTTP stream loads completely while the decoder is loading metadata.
2. The ResourceLoaded call from NotifyDownloadEnded returns early because mPlayState==LOADING.
3. The seeking performed by oggplay_get_duration while loading metadata results in mBytesDownloaded being reset to something < mTotalBytes.
4. FirstFrameLoaded doesn't call ResourceLoaded because mBytesDownload != mTotalBytes.
5. Decoder moves from DECODING to COMPLETED and fires PlaybackEnded, which cancels the media stream.

So step #5 is wrong, because it tied decoding to playback state, despite the fact that the decoder wasn't playing at all.  "ended" fired at an inappropriate time and the decoder started post-playback cleanup, including cancelling the active media stream which meant that "load" would not fire.  I noticed that "load" didn't fire, but that wasn't really the problem at all.  With different timing, it was possible to see a "load" event fired, but the decoder would still firing "ended" prematurely.  Attempting to play the file after this had happened would cause the decoder to reset and would usually appear to work as expected (despite a set of spurious events).

The same bug doesn't occur in current trunk, because the COMPLETED state in nsOggDecodeStateMachine waits for all queued decoded frames to be consumed before firing PlaybackEnded.  The logic dealing with this changed when the threaded oggplay_step_decode stuff landed (bug 474540) I think, but it may have been much harder to reproduce this bug ever since the media cache landed.