1246521 - Intermittent Youtube error "An error occurred. Please try again later"

Status: RESOLVED FIXED

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

Description

[Jean-Yves Avenard [:jya]]

This has happened a few times over the week-end while trying to reproduce bug 1246358.

This is on a "MacBook Pro (Retina, 13-inch, Early 2015)"

Unfortunately, I couldn't reproduce it after attempting to increase the log level which made it impossible to reproduce.
This typically happened immediately after starting. Either it would always fail until I restarted Nightly, or it would work fine.

This doesn't appear to be related to the media stack: there's no decoding error, demuxing error nor MSE error.

All I could see in this log was an init error related to graphics.

Unfortunately the logs appear to have disappeared (had to reboot the laptop).
Will post them again when I reproduce the problem or if I manage to exhume the logs.

I wonder if this is the same as bug 1235967.

Comment 1

[Jean-Yves Avenard [:jya]]

Attachment: erroryoutube.log

The error is:
[74954] WARNING: RasterImage::Init failed: file /Users/jyavenard/Work/Mozilla/mozilla-central/image/ImageFactory.cpp, line 109
[74954] WARNING: RasterImage::Init failed: file /Users/jyavenard/Work/Mozilla/mozilla-central/image/ImageFactory.cpp, line 109

This is the only thing abnormal I could find in the logs. When playback started, this warning didn't appear.

Comment 2

[Jean-Yves Avenard [:jya]]

Attachment: erroryoutube2.log

This times it happened with more logging, and much earlier; making for a rather short log:
We have the same two:
[5121] WARNING: RasterImage::Init failed: file /Users/jyavenard/Work/Mozilla/mozilla-central/image/ImageFactory.cpp, line 109
[5121] WARNING: RasterImage::Init failed: file /Users/jyavenard/Work/Mozilla/mozilla-central/image/ImageFactory.cpp, line 109

nightly was started with NSPR_LOG_MODULES=PlatformDecoderModule:5,MediaFormatReader:5,MediaDecoder:5

JW, can you see what is output the error? i see no error in those logs. What gives Youtube its cues that something wrong occurred?

Comment 3

[Jean-Yves Avenard [:jya]]

preliminary STR:

Somehow I managed to reproduce more often with this URL:
https://www.youtube.com/watch?v=JLf9q36UsBk&feature=youtu.be&t=254

It's likely unrelated as typically it happens when I restore from an old session.

But directly opening https://www.youtube.com/watch?v=JLf9q36UsBk&feature=youtu.be&t=254 as often produce the problem. (note that you need bug 1246358 applied, otherwise you'll hit another bug first)

Comment 4

[Jean-Yves Avenard [:jya]]

Attachment: erroryoutube3.log

Another log with just MediaDecoder:5,MediaSource:5

shows that there are no MSE error in there...

Comment 5

[Jean-Yves Avenard [:jya]]

This is youtube debug info.
{"ns":"yt","el":"detailpage","cpn":"QXsGf2vpomxg448r","docid":"JLf9q36UsBk","ver":2,"referrer":null,"cmt":"256.581","plid":"AAUrNyCfP2pfK338","ei":"nd63VqjdOsvH4AKwgo0g","fmt":"160","fs":"0","rt":"1658.822","of":"Y2jYQoPFrCFKbJ5Geg8v4A","adformat":null,"content_v":null,"euri":"","subscribed":null,"lact":38,"live":null,"cl":"113861800","mos":0,"osid":null,"state":"80","vm":"CAMQAQ","volume":100,"c":"WEB","cver":"html5","cplayer":"UNIPLAYER","cbr":"Chrome","cbrver":"46.0.2490.80","cos":"Windows","cosver":"6.1","hl":"en_US","cr":"AU","len":"256.581","fexp":"9406983,9416126,9420452,9422596,9423661,9423662","feature":"youtu.be","afmt":"250","vct":"0.000","vd":"NaN","vpl":"","vbu":"","vpa":true,"vsk":false,"ven":false,"vpr":1,"vrs":0,"vns":0,"vec":null,"vvol":0.6294337190892868,"debug_error":{"errorCode":"fmt.unplayable","errorDetail":"invalidState.1","message":"An error occurred. Please try again later.","messageKey":"YTP_ERROR_GENERIC_WITHOUT_LINK"},"debug_videoId":"JLf9q36UsBk","gpu":"Intel(R)_Iris(TM)_Graphics_6100","cgr":true,"debug_playbackQuality":"tiny","debug_date":"Mon Feb 08 2016 13:34:01 GMT+1100 (AEDT)"}

So at least this appear different to bug 1235967

Comment 6

[Jean-Yves Avenard [:jya]]

Ok found it.

This is a MSE error due to a race.

The audio track is shorter than the video track.
So the media element enter ended state due to the audio track finishing early. It may happen that YouTube is still trying to append new data.
https://dxr.mozilla.org/mozilla-central/source/dom/media/mediasource/SourceBuffer.cpp#544

The comment is good, but the test to check if the error attribute is not null is wrong. Being in Ended mode doesn't mean an error always occurred.

Comment 7

[Jean-Yves Avenard [:jya]]

Attachment: P1. Add MediaDecoderOwner::HasError method.

Comment 8

[Jean-Yves Avenard [:jya]]

Attachment: P2. Add MediaDecoder::OwnerHasError method.

Comment 9

[Jean-Yves Avenard [:jya]]

Attachment: [MSE] P3. Only error during Prepare Append algorithm if the media element is in error.

Comment 10

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Comment on attachment 8716844 [details] [diff] [review]
P2. Add MediaDecoder::OwnerHasError method.

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

r+ with nits:

::: dom/media/MediaDecoder.cpp
@@ +1046,5 @@
> +MediaDecoder::OwnerHasError() const
> +{
> +  MOZ_ASSERT(NS_IsMainThread());
> +
> +  return mShuttingDown || mOwner->HasError();

Empty line between statement, unlike the methods above and below. Consistency please!

::: dom/media/MediaDecoder.h
@@ +236,5 @@
>  
> +  // Return true if the decoder is in an error state or is shutting down.
> +  // A decoder is in an error state if the MediaDecoderOwner is in an error
> +  // state.
> +  bool OwnerHasError() const;

The function name doesn't quite match the meaning, it focuses on the owner error state at the expense of the shutdown state.
How about "HasErrorOrShutdown()", in the style of the method above?

Comment 11

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Comment on attachment 8716845 [details] [diff] [review]
[MSE] P3. Only error during Prepare Append algorithm if the media element is in error.

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

r+ with nit (related to a P2 nit) :

::: dom/media/mediasource/SourceBuffer.cpp
@@ +542,5 @@
>    // If the HTMLMediaElement.error attribute is not null, then throw an
>    // InvalidStateError exception and abort these steps.
>    if (!mMediaSource->GetDecoder() ||
> +      mMediaSource->GetDecoder()->OwnerHasError()) {
> +    MSE_DEBUG("HTMLMediaElement.error is not null");

OwnerHasError() could return true if the decoder is shutting down, but the debugging comment doesn't say anything about that.

Comment 12

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

(In reply to Gerald Squelart [:gerald] from comment #10)
> Comment on attachment 8716844 [details] [diff] [review]
> P2. Add MediaDecoder::OwnerHasError method.
> 
> Review of attachment 8716844 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> r+ with nits:
> 
> ::: dom/media/MediaDecoder.cpp
> @@ +1046,5 @@
> > +MediaDecoder::OwnerHasError() const
> > +{
> > +  MOZ_ASSERT(NS_IsMainThread());
> > +
> > +  return mShuttingDown || mOwner->HasError();
> 
> Empty line between statement, unlike the methods above and below.
> Consistency please!
> 
> ::: dom/media/MediaDecoder.h
> @@ +236,5 @@
> >  
> > +  // Return true if the decoder is in an error state or is shutting down.
> > +  // A decoder is in an error state if the MediaDecoderOwner is in an error
> > +  // state.
> > +  bool OwnerHasError() const;
> 
> The function name doesn't quite match the meaning, it focuses on the owner
> error state at the expense of the shutdown state.
> How about "HasErrorOrShutdown()", in the style of the method above?

After discussion with Jean-Yves, I see that the "shutdown" part is only needed to handle special cases where no owner is known.
So instead of changing the method name, I would suggest clarifying the comment, e.g.:
// Return true if the MediaDecoderOwner is in an error state.
// Note: If the decoder is shutting down, there is no owner and this is considered an error.

Knowing that, you may ignore my related nit in part 3.

Comment 13

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/de6c0f937e9f
https://hg.mozilla.org/integration/mozilla-inbound/rev/770d1bb1ca0c
https://hg.mozilla.org/integration/mozilla-inbound/rev/02c902f19190

Comment 14

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/de6c0f937e9f
https://hg.mozilla.org/mozilla-central/rev/770d1bb1ca0c
https://hg.mozilla.org/mozilla-central/rev/02c902f19190

Comment 15

[Jean-Yves Avenard [:jya]]

[Tracking Requested - why for this release]: Can cause YouTube stall

Comment 16

[Jean-Yves Avenard [:jya]]

correction above: Can cause YouTube errors.

Comment 17

[Sylvestre Ledru [:Sylvestre]]

Jean-Yves, could you fill the uplift request to aurora & beta? merci

Comment 18

[Jean-Yves Avenard [:jya]]

Comment on attachment 8716843 [details] [diff] [review]
P1. Add MediaDecoderOwner::HasError method.

Approval Request Comment
[Feature/regressing bug #]: 1246521
[User impact if declined]: YouTube will stop with a decode error; wrong MSE spec implementation emitting an error when it shouldn't
[Describe test coverage new/current, TreeHerder]:
[Risks and why]: Low. We're doing the right thing
[String/UUID change made/needed]: None

Comment 19

[Sylvestre Ledru [:Sylvestre]]

Comment on attachment 8716843 [details] [diff] [review]
P1. Add MediaDecoderOwner::HasError method.

Improve youtube support, taking it.
Should be in 45 beta 5.

Comment 20

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/2df14892dbc7
https://hg.mozilla.org/releases/mozilla-aurora/rev/e5b23bd2f129
https://hg.mozilla.org/releases/mozilla-aurora/rev/7d68fbe4a039

Comment 21

[Carsten Book [:Tomcat]]

has problems to apply to beta:

grafting 328332:2df14892dbc7 "Bug 1246521: P1. Add MediaDecoderOwner::HasError method. r=gerald, a=sylvestre"
merging dom/html/HTMLMediaElement.cpp
merging dom/html/HTMLMediaElement.h
merging dom/media/MediaDecoderOwner.h
merging dom/media/gtest/MockMediaDecoderOwner.h
warning: conflicts while merging dom/media/gtest/MockMediaDecoderOwner.h! (edit, then use 'hg resolve --mark')
abort: unresolved conflicts, can't continue
(use hg resolve and hg graft --continue)

Comment 22

[Jean-Yves Avenard [:jya]]

https://hg.mozilla.org/releases/mozilla-beta/rev/287f9cc975d1
https://hg.mozilla.org/releases/mozilla-beta/rev/9c5f9aec8a55
https://hg.mozilla.org/releases/mozilla-beta/rev/564aebef8e79