Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

MediaSource failures with certain language settings #1696

Closed
joeyparrish opened this issue Nov 21, 2018 · 20 comments
Closed

MediaSource failures with certain language settings #1696

joeyparrish opened this issue Nov 21, 2018 · 20 comments
Assignees
Labels
flag: Why didn't we catch this sooner This issue is embarassing; we may still need an automated test that could have prevented this issue status: archived Archived and locked; will not be updated type: bug Something isn't working correctly
Milestone

Comments

@joeyparrish
Copy link
Member

Have you read the FAQ and checked for duplicate open issues?:
Yes

What version of Shaka Player are you using?:
master / nightly

Can you reproduce the issue with our latest release version?:
No

Can you reproduce the issue with the latest code from master?:
Yes

Are you using the demo app or your own custom app?:
Demo

What browser and OS are you using?:
Chrome on Linux

What are the manifest and license server URIs?:
"Sintel 4k multicodec" from the asset list

What did you do?
Click load.

What did you expect to happen?
The content will load.

What actually happened?
A MediaSource error occurred: "Shaka Error MEDIA.VIDEO_ERROR (4,,DEMUXER_ERROR_COULD_NOT_OPEN)"

If you click load a second time, the content loads correctly.

https://nightly-dot-shaka-player-demo.appspot.com/demo/#asset=https://storage.googleapis.com/shaka-demo-assets/sintel/dash.mpd

@joeyparrish joeyparrish added the type: bug Something isn't working correctly label Nov 21, 2018
@joeyparrish joeyparrish added this to the v2.5 milestone Nov 21, 2018
@joeyparrish
Copy link
Member Author

Additional clues:

  1. This also reproduces with the MP4-only version of Sintel, but not with the WebM-only version.
  2. This does not reproduce if you have already loaded some other content. You must refresh the page and choose either MP4-only Sintel or multicodec Sintel as the first content you load.

@joeyparrish
Copy link
Member Author

joeyparrish commented Nov 21, 2018

Now I'm getting failures on the WebM-only version, too. Is this a race condition somewhere?

Using ";play" in the URL fragment and reloading the page, I got 19 failures out of 20 test runs.

@joeyparrish
Copy link
Member Author

The first commit in which this bug appears in 6b1ca2d, but it is still unclear how that could have caused this.

@joeyparrish
Copy link
Member Author

More specifically, this happens for me in Chrome/70.0.3538.110 on Linux, and with any of the Sintel assets on the first try, but not on the second try, and not with Angel One. This is not happening for @TheModMaker on the same version of Chrome.

@joeyparrish
Copy link
Member Author

The log from chrome:media-internals is sparse:

render_id: 47
player_id: 167
origin_url: http://localhost/
frame_url: http://localhost/shaka/demo/#asset=https://storage.googleapis.com/shaka-demo-assets/sintel-webm-only/dash.mpd;lang=de;play;build=uncompiled
frame_title: Shaka Player Demo
url: blob:http://localhost/2e1eafa1-82f5-4048-ac84-0ffd5a1eee5d
info: ChunkDemuxer: buffering by DTS
pipeline_state: kStopped
pipeline_error: DEMUXER_ERROR_COULD_NOT_OPEN
duration: 888.042

@joeyparrish
Copy link
Member Author

@wolenetz, any ideas on how we should debug this perplexing Chrome media error that only happens on this one machine, but not on an identical version of Chrome on the same OS on a teammate's machine?

@avelad
Copy link
Member

avelad commented Nov 22, 2018

@joeyparrish I have the same error:

1696

My useragent is "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.77 Safari/537.36" (Ubuntu 18.04)

@joeyparrish joeyparrish changed the title Failure to load multicodec version of Sintel in the demo MediaSource failures in Chrome on Linux Dec 3, 2018
@joeyparrish
Copy link
Member Author

This is still happening for me. This will block v2.5 if we can't solve it.

@joeyparrish joeyparrish added the flag: Why didn't we catch this sooner This issue is embarassing; we may still need an automated test that could have prevented this issue label Dec 4, 2018
@joeyparrish
Copy link
Member Author

I think I found the root cause, and I can explain why it doesn't happen for my teammates. @avelad, I notice that your language is set to es-ES. Mine is set to de. This is the trigger: a feature in Shaka Player which enables text display automatically when your language matches the text, but not the audio.

@wolenetz
Copy link

wolenetz commented Dec 4, 2018

I'll try building a debug chrome and get more detailed logs from a repro (assuming I can get a repro first...)

@wolenetz
Copy link

wolenetz commented Dec 4, 2018

No repro on Chrome Linux 70.3538.110, though language is 'en'.
But setting it to 'de' gets a repro. Faster repro URL:
https://nightly-dot-shaka-player-demo.appspot.com/demo/#asset=https://storage.googleapis.com/shaka-demo-assets/sintel/dash.mpd;lang=de;build=uncompiled

@wolenetz
Copy link

wolenetz commented Dec 4, 2018

The limited amount if info in chrome://media-internals for a repro suggests to me that this error occurs before reaching HAVE_METADATA. I'll dig into local repro logs next.

@wolenetz
Copy link

wolenetz commented Dec 4, 2018

I couldn't get a local tip-of-tree Chrome release build to repro this. I noticed also that even if I picked a specific "Text language" different from that in the URL and then click Load a second time that the chosen text language is not used. Is that a known issue, perhaps related?

@wolenetz
Copy link

wolenetz commented Dec 4, 2018

Ah I have a successful local repro now from tip-of-tree. Analyzing logs...

@wolenetz
Copy link

wolenetz commented Dec 4, 2018

Relevant portion of a repro log:

chunk_demuxer.cc(650)] AddId id=4bd9c84b-1517-4d18-a265-b566829cfc20 content_type=audio/webm codecs=opus
frame_processor.cc(300)] FrameProcessor()
webm_stream_parser.cc(124)] ChangeState() : 0 -> 1
chunk_demuxer.cc(1086)] GetGenerateTimestampsFlag(4bd9c84b-1517-4d18-a265-b566829cfc20)
source_buffer.cc(142)] SourceBuffer this=0x22fdca0d9480
source_buffer.cc(174)] setMode this=0x22fdca0d9480 newMode="segments"
chunk_demuxer.cc(1086)] GetGenerateTimestampsFlag(4bd9c84b-1517-4d18-a265-b566829cfc20)
chunk_demuxer.cc(1078)] IsParsingMediaSegment(4bd9c84b-1517-4d18-a265-b566829cfc20)
chunk_demuxer.cc(1095)] SetSequenceMode(4bd9c84b-1517-4d18-a265-b566829cfc20, 0)
frame_processor.cc(316)] SetSequenceMode(0)
media_source.cc(218)] addSourceBuffer this=0x63425043530 type="audio/webm; codecs=\"opus\"" -> 0x22fdca0d9480
media_source.cc(329)] isTypeSupported("video/webm;codecs=\"vp9\";framerate=\"23.80952380952381\";bitrate=\"204094\";width=\"426\";height=\"182\"") -> true
media_source.cc(329)] isTypeSupported("video/webm; codecs=\"vp9\"") -> true
media_source.cc(150)] addSourceBuffer this=0x63425043530 type="video/webm; codecs=\"vp9\""
media_source.cc(329)] isTypeSupported("video/webm; codecs=\"vp9\"") -> true
chunk_demuxer.cc(650)] AddId id=bdcb5d46-9e17-4f3b-8797-170b3dcc0972 content_type=video/webm codecs=vp9
frame_processor.cc(300)] FrameProcessor()
webm_stream_parser.cc(124)] ChangeState() : 0 -> 1
chunk_demuxer.cc(1086)] GetGenerateTimestampsFlag(bdcb5d46-9e17-4f3b-8797-170b3dcc0972)
source_buffer.cc(142)] SourceBuffer this=0x22fdca0d9840
source_buffer.cc(174)] setMode this=0x22fdca0d9840 newMode="segments"
chunk_demuxer.cc(1086)] GetGenerateTimestampsFlag(bdcb5d46-9e17-4f3b-8797-170b3dcc0972)
chunk_demuxer.cc(1078)] IsParsingMediaSegment(bdcb5d46-9e17-4f3b-8797-170b3dcc0972)
chunk_demuxer.cc(1095)] SetSequenceMode(bdcb5d46-9e17-4f3b-8797-170b3dcc0972, 0)
frame_processor.cc(316)] SetSequenceMode(0)
media_source.cc(218)] addSourceBuffer this=0x63425043530 type="video/webm; codecs=\"vp9\"" -> 0x22fdca0d9840
source_buffer.cc(680)] HighestPresentationTimestamp this=0x22fdca0d9480, pts=0
source_buffer.cc(680)] HighestPresentationTimestamp this=0x22fdca0d9840, pts=0
chunk_demuxer.cc(1036)] SetDuration(888.053)
html_media_element.cc(3303)] durationChanged(0xdd2cda69f38, 888.053, false)
html_media_element.cc(3310)] durationChanged(0xdd2cda69f38) : nan -> 888.053
media_source.cc(607)] SetReadyState this=0x63425043530 : "open" -> "ended"
chunk_demuxer.cc(1117)] MarkEndOfStream(0)
chunk_demuxer.cc(1214)] ReportError_Locked(12)
chunk_demuxer.cc(1198)] ChunkDemuxer::ChangeState_Locked() : 1 -> 4
html_media_element.cc(3303)] durationChanged(0xdd2cda69f38, 888.053, false)
webmediaplayer_impl.cc(1603)] OnError
der_media_log.cc(30)] MediaEvent: PIPELINE_ERROR DEMUXER_ERROR_COULD_NOT_OPEN
webmediaplayer_impl.cc(2603)] SetNetworkState(4)
html_media_element.cc(1698)] setNetworkState(0xdd2cda69f38, 4) - current state is 2
html_media_element.cc(1627)] MediaLoadingFailed(0xdd2cda69f38, 4, message='"DEMUXER_ERROR_COULD_NOT_OPEN"')
html_media_element.cc(1541)] NoneSupported(0xdd2cda69f38, message='"DEMUXER_ERROR_COULD_NOT_OPEN"')
media_source.cc(607)] SetReadyState this=0x63425043530 : "ended" -> "closed"
source_buffer.cc(655)] RemovedFromMediaSource this=0x22fdca0d9480
chunk_demuxer.cc(723)] RemoveId id=4bd9c84b-1517-4d18-a265-b566829cfc20
frame_processor.cc(305)] ~FrameProcessor()
source_buffer.cc(655)] RemovedFromMediaSource this=0x22fdca0d9840
chunk_demuxer.cc(723)] RemoveId id=bdcb5d46-9e17-4f3b-8797-170b3dcc0972
frame_processor.cc(305)] ~FrameProcessor()
:chunk_demuxer.cc(518)] Stop()
:chunk_demuxer.cc(1174)] Shutdown()
:chunk_demuxer.cc(1198)] ChunkDemuxer::ChangeState_Locked() : 4 -> 5
webmediaplayer_impl.cc(2829)] UpdatePlayState_ComputePlayState: is_remote=0, must_suspend=0, idle_suspended=0, background_suspended=0, can_stay_suspended=0, is_stale=0, have_future_data=0, paused_=1, seeking_=1
webmediaplayer_impl.cc(2685)] SetDelegateState(0, 1)
webmediaplayer_impl.cc(2746)] SetSuspendState(0)
html_media_element.cc(2511)] pause(0xdd2cda69f38)
html_media_element.cc(2518)] pauseInternal(0xdd2cda69f38)
html_media_element.cc(3510)] updatePlayState(0xdd2cda69f38) - shouldBePlaying = false, isPlaying = false
:INFO:CONSOLE(706)] "Player error", source: https://nightly-dot-shaka-player-demo.appspot.com/demo/main.js (706)

@joeyparrish
Copy link
Member Author

Requirements for repro:

  1. Auto text display is triggered based on language preferences
  2. Text stream setup is instant, but audio or video are not (DASH SegmentBase)

These conditions will cause StreamingEngine's setup phase to be completed after only text is initialized, which then causes a MediaSource failure for audio or video when streaming begins. Effectively, this is a race between two different triggers to StreamingEngine initialization.

@joeyparrish
Copy link
Member Author

@wolenetz, thank you for the assistance! We have found the root cause now within Shaka Player.

@joeyparrish joeyparrish changed the title MediaSource failures in Chrome on Linux MediaSource failures with certain language settings Dec 4, 2018
@joeyparrish
Copy link
Member Author

To answer the "Why didn't we catch this sooner?" label:

  1. The change was made in our private UI branch before we released the new UI, and the change was meant to fix a UI-related bug in text selection
  2. The bug is only triggered by our auto-display text feature, which is only triggered by certain language settings on certain content

Lessons learned:

When your colleague with an identical OS & browser can't repro, check your preferences!

@wolenetz
Copy link

wolenetz commented Dec 4, 2018

@joeyparrish Glad I could help - sorry about the delay. Of note, the path to error I found in my repro looks like mediaSource.endOfStream() was called before HAVE_METADATA readyState on the attached HTMLMediaElement was reached. I'll look into adding an informative error log message of some kind for that condition in Chrome in addition to the existing basic "DEMUXER_ERROR_COULD_NOT_OPEN" pipeline error message for this case.

@wolenetz
Copy link

wolenetz commented Dec 4, 2018

This is the related MSE spec issue that was hit by the repro: w3c/media-source#212

aarongable pushed a commit to chromium/chromium that referenced this issue Dec 5, 2018
…ages

If WebSourceBufferImpl::endOfStream() occurs prior to reaching
HAVE_METADATA (whether explicitly by application or as consequence of
other error condition spec's error), previously a generic
"DEMUXER_ERROR_COULD_NOT_OPEN" pipeline status error message might be
the only error message in chrome://media-internals for the player. This
change adds an extra error message to media-internals to assist
application debugging.

This change also adds more debug logging to Blink's MediaSource and
SourceBuffer implementations.

See also the known MSE spec issue around treatment of endOfStream() when
not yet having reached HAVE_METADATA:
w3c/media-source#212

TEST=Manual verification of the new MEDIA_LOG mentioned in the first
paragraph of this description (via repro of
shaka-project/shaka-player#1696), updated
ChunkDemuxerTests

Change-Id: I2044fc2484160a02506210eedeee7bf794da1da0
Reviewed-on: https://chromium-review.googlesource.com/c/1361936
Commit-Queue: Matthew Wolenetz <wolenetz@chromium.org>
Reviewed-by: Dan Sanders <sandersd@chromium.org>
Cr-Commit-Position: refs/heads/master@{#614046}
shaka-bot pushed a commit that referenced this issue Dec 8, 2018
Vaguely relates to the investigation into issue #1696

Change-Id: I5d16f5cbdabf72361598e28bff196a5be7030967
shaka-bot pushed a commit that referenced this issue Dec 8, 2018
This is fairly tricky to reproduce.

First, we must trigger the auto-display of subtitles.  We didn't have
any tests that covered this before, so we needed this anyway.  This is
triggered by careful choice of content language and language
preferences, which required us to add language information to our
simulated test content.  I also added tests for the cases where we
should *not* trigger auto-display of subtitles.

Second, the setup phase for text must complete more quickly than the
setup for audio & video.  In real life, this happens when text is
non-segmented VTT and audio & video use DASH's SegmentBase.  In the
test, this is accomplished by delaying createSegmentIndex() of
audio and video in our simulated content.

This will cause auto-display of subtitles to trigger a setup race in
StreamingEngine.  When text wins the race, MediaSource errors follow
for audio and video.

Issue #1696

Change-Id: I1c22089925486da642368bec269a55d8556900d1
@shaka-project shaka-project locked and limited conversation to collaborators Feb 6, 2019
@shaka-bot shaka-bot added the status: archived Archived and locked; will not be updated label Apr 15, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
flag: Why didn't we catch this sooner This issue is embarassing; we may still need an automated test that could have prevented this issue status: archived Archived and locked; will not be updated type: bug Something isn't working correctly
Projects
None yet
Development

No branches or pull requests

4 participants