MediaSource MP4 video playback stutters, does not display every frame
Reported by
grigoryy...@gmail.com,
Sep 22 2017
|
||||||||||
Issue descriptionUserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/60.0.3112.113 Safari/537.36 Steps to reproduce the problem: It is tricky to reproduce on your end because you need a websocket server streaming MP4 video to you. What is the expected behavior? Video playback should be smooth, every video frame should be displayed on screen. What went wrong? See the attached Chrome performance log. You can see that decodeAndDisplayVideo() method is called about every 20-30ms (as it should). But display frames are much longer and irregular, so multiple frames are decoded but only occasionally displayed to the user. Did this work before? No Does this work in other browsers? N/A Chrome version: 60.0.3112.113 Channel: stable OS Version: 10.0 Flash Version: We can help by providing video streaming endpoint on our server.
,
Sep 26 2017
@Reporter:Could you please help in providing any web URL to test and confirm this.
,
Sep 28 2017
,
Sep 28 2017
Sorry, providing a server endpoint proves a bit difficult because we are behind firewalls. I am trying to create a minimal server you can run yourself with websocketm & ffmpeg.
,
Sep 28 2017
Thank you for providing more feedback. Adding requester "divya.padigela@techmahindra.com" to the cc list and removing "Needs-Feedback" label. For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
,
Oct 4 2017
,
Oct 13 2017
,
Oct 13 2017
What does chrome://media-internals say about the playback?
,
Oct 13 2017
Also, does this issue reproduce on M63 (currently available in Chrome canary and dev channels)?
,
Oct 17 2017
chrome://media-internals/: render_id: 7 player_id: 48 origin_url: http://localhost:8080/ frame_url: http://localhost:8080/ frame_title: Video Streaming Server url: blob:http://localhost:8080/247ed61c-3eb4-4c7d-ad3e-d8f25edf91d8 pipeline_state: kPlaying found_video_stream: true video_codec_name: h264 debug: Video rendering in low delay mode. video_dds: false video_decoder: FFmpegVideoDecoder video_buffering_state: BUFFERING_HAVE_NOTHING height: 1080 width: 1920 pipeline_buffering_state: BUFFERING_HAVE_NOTHING event: PLAY duration: unknown Log: 00:00:00 00 origin_url http://localhost:8080/ 00:00:00 00 frame_url http://localhost:8080/ 00:00:00 00 frame_title Video Streaming Server 00:00:00 00 url blob:http://localhost:8080/247ed61c-3eb4-4c7d-ad3e-d8f25edf91d8 00:00:00 00 pipeline_state kStarting 00:00:01 725 found_video_stream true 00:00:01 725 video_codec_name h264 00:00:01 726 debug Video rendering in low delay mode. 00:00:01 726 video_dds false 00:00:01 726 video_decoder FFmpegVideoDecoder 00:00:01 726 pipeline_state kPlaying 00:00:01 731 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:01 731 height 1080 00:00:01 731 width 1920 00:00:01 731 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:01 731 event PLAY 00:00:01 827 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:01 828 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:01 725 duration unknown 00:00:02 377 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:02 377 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:02 427 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:02 428 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:02 575 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:02 575 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:02 609 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:02 609 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:02 642 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:02 642 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:02 709 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:02 709 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:02 907 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:02 907 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:02 942 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:02 942 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:03 75 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:03 75 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:03 108 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:03 108 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:03 203 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:03 203 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:03 237 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:03 237 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:03 339 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:03 339 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:03 374 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:03 374 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:03 477 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:03 477 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:03 511 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:03 511 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:03 576 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:03 577 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:03 627 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:03 628 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:03 844 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:03 844 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:03 880 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:03 880 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:03 912 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:03 912 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:03 978 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:03 978 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:04 212 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:04 212 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:04 261 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:04 261 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:04 485 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:04 485 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:04 494 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:04 494 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:04 520 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:04 520 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:04 561 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:04 561 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:04 651 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:04 651 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:04 660 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:04 660 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:04 718 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:04 718 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:04 727 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:04 728 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:04 750 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:04 750 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:04 795 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:04 795 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:04 915 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:04 915 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:04 961 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:04 961 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:05 114 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:05 114 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:05 128 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:05 128 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:05 149 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:05 149 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:05 194 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:05 194 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:00:05 347 video_buffering_state BUFFERING_HAVE_ENOUGH 00:00:05 347 pipeline_buffering_state BUFFERING_HAVE_ENOUGH 00:00:36 696 video_buffering_state BUFFERING_HAVE_NOTHING 00:00:36 696 pipeline_buffering_state BUFFERING_HAVE_NOTHING 00:02:11 392 video_buffering_state BUFFERING_HAVE_ENOUGH 00:02:11 393 pipeline_buffering_state BUFFERING_HAVE_ENOUGH
,
Oct 17 2017
Thank you for providing more feedback. Adding requester "beccahughes@chromium.org" to the cc list and removing "Needs-Feedback" label. For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
,
Oct 17 2017
Interestingly enough it doesn't work at all on the M63 version, fails with this exception on video.play() Uncaught (in promise) DOMException: Failed to load because no supported source was found. Promise (async) connectToServer @ (index):143
,
Oct 17 2017
Looks like we're running out of frames so we are underflowing. I'd guess you need to append more frame data since otherwise we're stalling. You'll need at least 2+ frames in the buffer at all times. No idea why it's not working in M63.
,
Oct 17 2017
Just look at the performance log attached to the bug. Frames are coming at a steady pace, 20+ per second. But they are not displayed as they come, the display frames are irregular and don't coincide with the time the frame is received and decoded. In short, it looks like 'swapBuffers()' or something like that to force redisplay is not called in 'decodeAndDisplayVideo()'. Don't read too much into BUFFERING_HAVE_NOTHING, it's a natural state when you have an incoming stream: the latest frame is already decoded, waiting for the next one. The problem is that the latest decoded frame is not shown to the user.
,
Oct 17 2017
@#12, what does M63 MediaError.message show for the error attribute on the element when the promise is rejected? Also, what does chrome://media-internals show for such a video.play() promise's rejection? I suspect it's occurring due to a fatal MSE append error prior to reaching HAVE_METADATA state (e.g. from this line: https://cs.chromium.org/chromium/src/third_party/WebKit/Source/core/html/media/HTMLMediaElement.cpp?type=cs&sq=package:chromium&l=1635), but it's unclear to me why that would be specific to M63 without knowing more. cc+=mlamouri@ in case something about play promise rejection in M63 has regressed.
,
Oct 17 2017
The buffering_have_nothing is the reason why frames are stuttering and skipping. If you underflow we require at least 2 frames to restart even in low delay mode. Triggering this process at all will cause irregular timing since we pause until the frames are ready, taking us out of sync with the compositor clock. If you want playback to be smooth you must avoid bouts of underflow like this. You can try adding a silent audio track which we will favor for the clock instead. So long as audio is available we give video 3 seconds to rebuffer before pausing. We could do better here by driving the clock purely based on the displayed video frames; today we instead base the clock on the system clock which leads to underflow issues like this. I've been thinking about this but haven't had time to follow up on this.
,
Oct 18 2017
Thanks for the explanation! We will try to add a silent audio track to test it out, thanks for the suggestion. But I think talking about 'underflaw' is strange in this context. The source of the video is real-time 3D rendering, it is not possible to "look ahead" in this scenario, the latency is critical and we send frames as soon as we can. Videochat application would be a similar scenario, are there ways to address stutter without adding audio for these scenarios?
,
Oct 18 2017
On M63 failure: I see no other properties on the exception object other than 'message'. This is what media-internals say: render_id: 6 player_id: 10 origin_url: http://localhost:8080/ frame_url: http://localhost:8080/ frame_title: Video Streaming Server url: blob:http://localhost:8080/3767c1ab-1a9f-41a2-8423-d48394bcc83b info: ChunkDemuxer: buffering by DTS pipeline_state: kStopped error: Append: stream parsing failed. Data size=1390 append_window_start=0 append_window_end=inf pipeline_error: CHUNK_DEMUXER_ERROR_APPEND_FAILED
,
Oct 18 2017
@#18, for future reference, the 'message' attribute to which I was referring was that on the MediaError object available if there's been an error via HTMLMediaElement.error. Based on the details in #18, it would probably just contain a concatenation of pipeline_error and error details listed in that media-internals snippet, so unlikely any further usable information. However, the snippet (and likely HTMLMediaElement.error.message) indicate that there was a parse failure. In M63, we have addressed some edge cases that the parser may have previously allowed. Greater amount of detail on the underlying parse error may be available by inspecting the output of a Debug-built version of chromium on a repro. If you have a narrow sample of the failing append/parse sequence that you can share with us, we can help identify which of the many possible kinds of parse error is being hit. Otherwise, if you could build your own Debug version of Chromium and try it out with --v=4 on a repro, the output may illuminate why M63 is no longer accepting your media.
,
Oct 24 2017
@#19, I have finally managed to build debug Chrome on Linux, but with --v=4 it is so slow that it never actually starts - just spews more and more debug info into the window. Is there some way to limit this output to just the modules we need?
,
Oct 24 2017
@#20 something like this may help you: --v=3 --vmodule=MediaSource*=3,HTMLMediaSource*=3,SourceBuffer*=3,HTMLMediaElement*=3,chunk*=3,source*=3,media*=3,webmed*=3,websou*=3,frame_pro*=3,webm*=3,mp4*=3,mp3*=3,box_*=3,avc*=3,aac*=3,es_*=3,track_*=3,cenc*=3,ffmpeg*=3,decoder_stream*=2,*=0 These globs are based on the source filename from which the log originates, so adjust to remove/add desired modules. The above is a good starting point usually.
,
Oct 25 2017
@#21 did that, but doesn't look very useful: [1:1:1025/145244.210605:VERBOSE3:HTMLMediaElement.cpp(2314)] play(0x358562a04dd0) [1:1:1025/145244.211049:VERBOSE3:HTMLMediaElement.cpp(2346)] playInternal(0x358562a04dd0) [1:1:1025/145244.211312:VERBOSE3:HTMLMediaElement.cpp(1886)] setIgnorePreloadNone(0x358562a04dd0) [1:1:1025/145244.211517:VERBOSE1:webmediaplayer_impl.cc(775)] SetPreload(2) [1:1:1025/145244.211691:VERBOSE3:HTMLMediaElement.cpp(3364)] updatePlayState(0x358562a04dd0) - shouldBePlaying = false, isPlaying = false [30169:30169:1025/145244.216885:INFO:CONSOLE(150)] "[object Promise]", source: http://10.21.80.104:8080/ (150) [30169:30169:1025/145244.308987:INFO:CONSOLE(92)] "Received 1390", source: http://10.21.80.104:8080/ (92) [30169:30169:1025/145244.310579:INFO:CONSOLE(93)] "Uncaught TypeError: Cannot read property 'updating' of undefined", source: http://10.21.80.104:8080/ (93) [30169:30169:1025/145244.358681:INFO:CONSOLE(92)] "Received 184723", source: http://10.21.80.104:8080/ (92) [30169:30169:1025/145244.360262:INFO:CONSOLE(93)] "Uncaught TypeError: Cannot read property 'updating' of undefined", source: http://10.21.80.104:8080/ (93) [30169:30169:1025/145244.385427:INFO:CONSOLE(92)] "Received 175546", source: http://10.21.80.104:8080/ (92) I'll try to create a file to debug on your side.
,
Oct 25 2017
If you can't look ahead you'll have to defer until a couple frames are available. You might also consider rendering to a canvas instead of using <video> as well. That said the old behavior should have shown similar issues, if you didn't provide a frame in time we'd end up with an extra long frame and depending on the timing of the next vsync either the next frame might get chosen or the one after it. The new code just forces this to always happen vs sometimes happen. I think we can get some of the old behavior back by preserving average frame duration across underflow events and using that for effective frames queued. I'll try to find some time to investigate this.
,
Nov 29 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/21ece16c7d9e0d06786579e7d86a7993a706f656 commit 21ece16c7d9e0d06786579e7d86a7993a706f656 Author: Dale Curtis <dalecurtis@chromium.org> Date: Wed Nov 29 02:10:55 2017 Use video frame duration metadata instead of waiting for 2 frames. http://crrev.com/493874 changed the low delay case to wait for two frames since we need to be sure we don't resume until we actually have valid frames since the first frame was valid forever without duration information. It turns out we actually do have duration infromation hanging off the DecoderStream, so use this information and set it as the FRAME_DURATION metadata key for each VideoFrame. We can then have the algorithm use this information for the estimated end time of frames when only a single frame is present in the queue. Note: The video-canvas layout test was showing the wrong frame; I manually extracted the frames and verified that before we were showing the "7" frame when pts=2.0s == "6" frame. I've updated the test expectations appropriately. BUG= 786576 , 767878 ,709302 TEST=new unittest, old unittests pass w/o modification, manual test of 4k60 vp9 low latency content doesn't exhibit multiple stalls after returning to the foreground when the video track has been disabled, manual test with https://jsfiddle.net/u3enjLzz/ Cq-Include-Trybots: master.tryserver.chromium.android:android_optional_gpu_tests_rel;master.tryserver.chromium.linux:linux_optional_gpu_tests_rel;master.tryserver.chromium.mac:mac_optional_gpu_tests_rel;master.tryserver.chromium.win:win_optional_gpu_tests_rel Change-Id: I963903d6a173038a2d534db4e040c8f4774825b5 Reviewed-on: https://chromium-review.googlesource.com/780267 Commit-Queue: Dale Curtis <dalecurtis@chromium.org> Reviewed-by: Matthew Wolenetz <wolenetz@chromium.org> Cr-Commit-Position: refs/heads/master@{#519961} [modify] https://crrev.com/21ece16c7d9e0d06786579e7d86a7993a706f656/media/filters/video_renderer_algorithm.cc [modify] https://crrev.com/21ece16c7d9e0d06786579e7d86a7993a706f656/media/filters/video_renderer_algorithm.h [modify] https://crrev.com/21ece16c7d9e0d06786579e7d86a7993a706f656/media/filters/video_renderer_algorithm_unittest.cc [modify] https://crrev.com/21ece16c7d9e0d06786579e7d86a7993a706f656/media/renderers/video_renderer_impl.cc [modify] https://crrev.com/21ece16c7d9e0d06786579e7d86a7993a706f656/media/renderers/video_renderer_impl.h [modify] https://crrev.com/21ece16c7d9e0d06786579e7d86a7993a706f656/third_party/WebKit/LayoutTests/media/video-canvas.html [delete] https://crrev.com/afedd691d118f767302c309ffa7b337ae07ca13e/third_party/WebKit/LayoutTests/platform/linux/media/video-canvas-expected.txt
,
Nov 29 2017
,
Nov 29 2017
Fixed, should be available in 64.0.3281.0 and higher.
,
Dec 1 2017
I have verified that the issue is fixed for us. Thanks a ton, guys! |
||||||||||
►
Sign in to add a comment |
||||||||||
Comment 1 by jmukthavaram@chromium.org
, Sep 25 2017