Bug 219565

Summary: REGRESSSION(270435) [GStreamer] Many media source tests failing and timing out
Product: WebKit Reporter: Lauro Moura <lmoura>
Component: MediaAssignee: Lauro Moura <lmoura>
Status: RESOLVED FIXED    
Severity: Normal CC: bugs-noreply, calvaris, cgarcia, dbates, dpino, ews-watchlist, gustavo, menard, peng.liu6, pnormand, vjaquez, webkit-bug-importer
Priority: P2 Keywords: InRadar
Version: WebKit Nightly Build   
Hardware: Unspecified   
OS: Unspecified   
See Also: https://bugs.webkit.org/show_bug.cgi?id=219332
https://bugs.webkit.org/show_bug.cgi?id=219822
Attachments:
Description Flags
Patch
none
Updated patch after r270612
none
Patch with updated expectations
none
Patch none

Lauro Moura
Reported 2020-12-04 20:47:58 PST
In media/media-source: Expected: 71 passes, 2 failures, 4 flakies After r270435: 59 passes, 15 timeouts media/media-source/media-source-abort-resets-parser.html media/media-source/media-source-canplaythrough-event.html media/media-source/media-source-error-crash.html media/media-source/media-source-init-segment-duration.html media/media-source/media-source-paint-to-canvas.html media/media-source/media-source-remove-crash.html media/media-source/media-source-resize.html media/media-source/media-source-samples-resolution-change.html media/media-source/media-source-seek-detach-crash.html media/media-source/media-source-seek-redundant-append.html media/media-source/media-source-seek-twice.html media/media-source/media-source-stalled-holds-sleep-assertion.html media/media-source/media-source-trackid-change.html media/media-source/media-source-unnecessary-seek-seeked.html media/media-source/media-source-webm-init-inside-segment.html Other tests are failing too. Collecting their data in the following comments.
Attachments
Patch (2.06 KB, patch)
2020-12-09 10:31 PST, Peng Liu
no flags
Updated patch after r270612 (23.11 KB, patch)
2020-12-10 21:55 PST, Lauro Moura
no flags
Patch with updated expectations (28.89 KB, patch)
2020-12-11 22:05 PST, Lauro Moura
no flags
Patch (28.78 KB, patch)
2020-12-14 01:42 PST, Philippe Normand
no flags
Lauro Moura
Comment 1 2020-12-04 20:54:28 PST
Checking media/media-source/media-source-error-crash.html, it seems it's getting stuck somewhere waiting for events after an appendBuffer command. With GST_DEBUG=7 (trace, generated a 20MB text file), the last mentions of webkitmse are the following: 0:00:00.964280978 106 0x5636a23af610 DEBUG webkitmse MediaPlayerPrivateGStreamerMSE.cpp:712:trackDetected: track ID: V1, caps: video/x-h264, stream-format=(string)avc, alignment=(string)au, level=(string)3, profile=(string)main, codec_data=(buffer)014d401eff010013274d401ea9181407b600d4180418c2b5ef7c0401000428de09c8, width=(int)640, height=(int)480, pixel-aspect-ratio=(fraction)1/1 0:00:00.964318730 106 0x5636a23af610 DEBUG webkitmse PlaybackPipeline.cpp:178:attachTrack:<source> Configured track V1: appsrc=appsrc1, padId=0, mediaType=video/x-h264 0:00:00.982215860 106 0x5636a27692a0 DEBUG webkitmse AppendPipeline.cpp:684:connectDemuxerSrcPadToAppsinkFromStreamingThread: connecting to appsink 0:00:00.982220189 106 0x5636a27692a0 WARN webkitmse AppendPipeline.cpp:687:connectDemuxerSrcPadToAppsinkFromStreamingThread: Only one stream per SourceBuffer is allowed! Ignoring stream 2 by adding a black hole probe. 0:00:00.982249044 106 0x5636a27692a0 DEBUG webkitmse AppendPipeline.cpp:208:operator(): Posting no-more-pads task to main thread 0:00:00.982269273 106 0x5636a23af610 DEBUG webkitmse AppendPipeline.cpp:508:didReceiveInitializationSegment: Notifying SourceBuffer for track V1 0:00:00.982533950 106 0x5636a27692a0 DEBUG webkitmse AppendPipeline.cpp:897:appendPipelineAppsinkPadEventProbe: Handling event stream-start on append pipeline appsinkPad 0:00:00.984564192 106 0x5636a27692a0 DEBUG webkitmse AppendPipeline.cpp:897:appendPipelineAppsinkPadEventProbe: Handling event caps on append pipeline appsinkPad Without the revision, the test has the same messages as above, but followed by the normal flow (after the last common message, about handling event caps): 0:00:00.970354434 106 0x559cb7897e10 TRACE webkitmse AppendPipeline.cpp:560:consumeAppsinkAvailableSamples:<append-pipeline-video-mp4-0> batchedSampleCount = 0 0:00:00.970533065 106 0x559cb7897e10 DEBUG webkitmse MediaPlayerPrivateGStreamerMSE.cpp:712:trackDetected: track ID: V1, caps: video/x-h264, stream-format=(string)avc, alignment=(string)au, level=(string)3, profile=(string)main, codec_data=(buffer)014d401effe10013274d401ea9181407b600d4180418c2b5ef7c0401000428de09c8, width=(int)640, height=(int)480, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)0/1, chroma-format=(string)4:2:0, bit-depth-luma=(uint)8, bit-depth-chroma=(uint)8, colorimetry=(string)2:4:5:4, parsed=(boolean)true 0:00:00.970589302 106 0x559cb7897e10 DEBUG webkitmse PlaybackPipeline.cpp:220:reattachTrack: Re-attaching track 0:00:00.972209093 106 0x559cb7c52cc0 WARN webkitmse AppendPipeline.cpp:303:handleErrorSyncMessage:<append-pipeline-video-mp4-0> Demuxing error: error message: 0x559cb7ff4620, time 99:99:99.999999999, seq-num 165, element 'qtdemux0', GstMessageError, gerror=(GError)NULL, debug=(string)"../gst/isomp4/qtdemux.c\(7009\):\ gst_qtdemux_process_adapter\ \(\):\ /GstPipeline:append-pipeline-video-mp4-0/GstQTDemux:qtdemux0:\012atom\ ....\ has\ bogus\ size\ 18446744073709551615";
Lauro Moura
Comment 2 2020-12-04 20:56:49 PST
In imported/w3c/web-platform-tests/encrypted-media/: Expected: 34 passes, 3 failures, and 5 flakies Actual: 20 passes, 18 timeouts imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-clear-encrypted.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-encrypted-clear-sources.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-encrypted-clear.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-events.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-multikey-sequential-readyState.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-multikey-sequential.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-multikey.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-multisession.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-setMediaKeys-after-src.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-setMediaKeys-after-update.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-setMediaKeys-onencrypted.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-two-videos.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-waitingforkey.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-setmediakeys-again-after-playback.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-setmediakeys-again-after-resetting-src.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-setmediakeys-multiple-times-with-different-mediakeys.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-waiting-for-a-key.https.html
Lauro Moura
Comment 3 2020-12-04 20:57:50 PST
* Properly formatted list imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-clear-encrypted.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-encrypted-clear-sources.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-encrypted-clear.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-events.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-multikey-sequential-readyState.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-multikey-sequential.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-multikey.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-multisession.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-setMediaKeys-after-src.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-setMediaKeys-after-update.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-setMediaKeys-onencrypted.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-two-videos.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary-waitingforkey.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-playback-temporary.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-setmediakeys-again-after-playback.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-setmediakeys-again-after-resetting-src.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-setmediakeys-multiple-times-with-different-mediakeys.https.html imported/w3c/web-platform-tests/encrypted-media/clearkey-mp4-waiting-for-a-key.https.html
Lauro Moura
Comment 4 2020-12-04 21:36:46 PST
In imported/w3c/web-platform-tests/media-source/: Expected: 45 passes, 18 failures, and 8 flakies Actual: 15 passes and 49 timeouts imported/w3c/web-platform-tests/media-source/mediasource-activesourcebuffers.html imported/w3c/web-platform-tests/media-source/mediasource-append-buffer.html imported/w3c/web-platform-tests/media-source/mediasource-appendbuffer-quota-exceeded.html imported/w3c/web-platform-tests/media-source/mediasource-appendwindow.html imported/w3c/web-platform-tests/media-source/mediasource-avtracks.html imported/w3c/web-platform-tests/media-source/mediasource-buffered-seek.html imported/w3c/web-platform-tests/media-source/mediasource-buffered.html imported/w3c/web-platform-tests/media-source/mediasource-changetype-play-implicit.html imported/w3c/web-platform-tests/media-source/mediasource-changetype-play-negative.html imported/w3c/web-platform-tests/media-source/mediasource-changetype-play-without-codecs-parameter.html imported/w3c/web-platform-tests/media-source/mediasource-changetype-play.html imported/w3c/web-platform-tests/media-source/mediasource-changetype.html imported/w3c/web-platform-tests/media-source/mediasource-config-change-mp4-a-bitrate.html imported/w3c/web-platform-tests/media-source/mediasource-config-change-mp4-av-audio-bitrate.html imported/w3c/web-platform-tests/media-source/mediasource-config-change-mp4-av-framesize.html imported/w3c/web-platform-tests/media-source/mediasource-config-change-mp4-av-video-bitrate.html imported/w3c/web-platform-tests/media-source/mediasource-config-change-mp4-v-bitrate.html imported/w3c/web-platform-tests/media-source/mediasource-config-change-mp4-v-framerate.html imported/w3c/web-platform-tests/media-source/mediasource-config-change-mp4-v-framesize.html imported/w3c/web-platform-tests/media-source/mediasource-config-change-webm-a-bitrate.html imported/w3c/web-platform-tests/media-source/mediasource-config-change-webm-av-audio-bitrate.html imported/w3c/web-platform-tests/media-source/mediasource-config-change-webm-av-framesize.html imported/w3c/web-platform-tests/media-source/mediasource-config-change-webm-av-video-bitrate.html imported/w3c/web-platform-tests/media-source/mediasource-config-change-webm-v-bitrate.html imported/w3c/web-platform-tests/media-source/mediasource-config-change-webm-v-framerate.html imported/w3c/web-platform-tests/media-source/mediasource-config-change-webm-v-framesize.html imported/w3c/web-platform-tests/media-source/mediasource-correct-frames-after-reappend.html imported/w3c/web-platform-tests/media-source/mediasource-correct-frames.html imported/w3c/web-platform-tests/media-source/mediasource-detach.html imported/w3c/web-platform-tests/media-source/mediasource-duration-boundaryconditions.html imported/w3c/web-platform-tests/media-source/mediasource-duration.html imported/w3c/web-platform-tests/media-source/mediasource-endofstream.html imported/w3c/web-platform-tests/media-source/mediasource-errors.html imported/w3c/web-platform-tests/media-source/mediasource-getvideoplaybackquality.html imported/w3c/web-platform-tests/media-source/mediasource-h264-play-starved.html imported/w3c/web-platform-tests/media-source/mediasource-liveseekable.html imported/w3c/web-platform-tests/media-source/mediasource-play-then-seek-back.html imported/w3c/web-platform-tests/media-source/mediasource-play.html imported/w3c/web-platform-tests/media-source/mediasource-redundant-seek.html imported/w3c/web-platform-tests/media-source/mediasource-remove.html imported/w3c/web-platform-tests/media-source/mediasource-removesourcebuffer.html imported/w3c/web-platform-tests/media-source/mediasource-replay.html imported/w3c/web-platform-tests/media-source/mediasource-seek-beyond-duration.html imported/w3c/web-platform-tests/media-source/mediasource-seek-during-pending-seek.html imported/w3c/web-platform-tests/media-source/mediasource-seekable.html imported/w3c/web-platform-tests/media-source/mediasource-sequencemode-append-buffer.html imported/w3c/web-platform-tests/media-source/mediasource-sourcebuffer-mode.html imported/w3c/web-platform-tests/media-source/mediasource-timestamp-offset.html imported/w3c/web-platform-tests/media-source/mediasource-video-is-visible.html
Lauro Moura
Comment 5 2020-12-04 21:50:04 PST
Tentative gardening in r270469
Diego Pino
Comment 6 2020-12-06 23:36:16 PST
(In reply to Lauro Moura from comment #5) > Tentative gardening in r270469 Also r270471 and r270495.
Philippe Normand
Comment 7 2020-12-09 08:36:35 PST
Well, clang is helpful about this... ../../Source/WebCore/platform/graphics/gstreamer/mse/SourceBufferPrivateGStreamer.cpp:185:1: warning: all paths through this function will call itself [-Winfinite-recursion] { ^ ../../Source/WebCore/platform/graphics/gstreamer/mse/SourceBufferPrivateGStreamer.cpp:190:1: warning: all paths through this function will call itself [-Winfinite-recursion] { ^ 2 warnings generated. I suspect this is the culprit.
Philippe Normand
Comment 8 2020-12-09 08:40:34 PST
Just remove the recursing calls and leave implementation of these methods empty. rs=me ;)
Philippe Normand
Comment 9 2020-12-09 09:05:19 PST
(In reply to Philippe Normand from comment #8) > Just remove the recursing calls and leave implementation of these methods > empty. rs=me ;) Ah, I mean, chain to parent class method implementation
Peng Liu
Comment 10 2020-12-09 10:13:58 PST
(In reply to Philippe Normand from comment #7) > Well, clang is helpful about this... > > ../../Source/WebCore/platform/graphics/gstreamer/mse/ > SourceBufferPrivateGStreamer.cpp:185:1: warning: all paths through this > function will call itself [-Winfinite-recursion] > { > ^ > ../../Source/WebCore/platform/graphics/gstreamer/mse/ > SourceBufferPrivateGStreamer.cpp:190:1: warning: all paths through this > function will call itself [-Winfinite-recursion] > { > ^ > 2 warnings generated. > > > I suspect this is the culprit. Oops! Sorry for the mistake. :-(
Peng Liu
Comment 11 2020-12-09 10:31:44 PST
Lauro Moura
Comment 12 2020-12-10 21:55:50 PST
Created attachment 415967 [details] Updated patch after r270612 Still some failures related to r270612, though.
Lauro Moura
Comment 13 2020-12-10 22:02:23 PST
After this, there are still a few failures, likely related to timeouts after r270612. For example, with media/media-source/media-source-seek-twice.html, the test times out while waiting for the first seek event. GST webkitmse trace output: 0:00:01.224777512 106 0x55905b9e5610 INFO webkitmse MediaPlayerPrivateGStreamerMSE.cpp:167:seek:<media-player-0> [Seek] seek attempt to {-1/1 = nan} secs 0:00:01.224833488 106 0x55905b9e5610 DEBUG webkitmse MediaPlayerPrivateGStreamerMSE.cpp:186:seek:<media-player-0> Seeking from {0/1 = 0.000000} to {-1/1 = nan} seconds 0:00:01.224872773 106 0x55905b9e5610 DEBUG webkitmse MediaPlayerPrivateGStreamerMSE.cpp:261:doSeek:<media-player-0> [Seek] cannot seek, current state change is FAILURE 0:00:01.224882762 106 0x55905b9e5610 WARN webkitmse MediaPlayerPrivateGStreamerMSE.cpp:193:seek:<media-player-0> Seeking to {-1/1 = nan} failed 0:00:15.715545364 106 0x55905b9e5610 DEBUG webkitmse PlaybackPipeline.cpp:150:removeSourceBuffer:<source> Element removed from MediaSource 0:00:15.716031378 106 0x55905b9e5610 TRACE webkitmse MediaPlayerPrivateGStreamerMSE.cpp:115:~MediaPlayerPrivateGStreamerMSE: destroying the player (0x7f9cfccc9700) 0:00:15.716046066 106 0x55905b9e5610 DEBUG webkitmse PlaybackPipeline.cpp:95:setWebKitMediaSrc: webKitMediaSrc=(nil) Looking into MediaSource.cpp, in comparison to the behavior before r270612, one difference I could find was the buffered() call now returning an empty range list, causing hasCurrentTime to return false and the ReadyState always being kept in the HaveMetadata state (in MediaSource::monitorSourceBuffers()).
Lauro Moura
Comment 14 2020-12-10 22:20:27 PST
This investigation was done on top of r270630. Tomorrow I'll check it against r270639 (seeking support).
Lauro Moura
Comment 15 2020-12-11 05:50:17 PST
(In reply to Lauro Moura from comment #14) > This investigation was done on top of r270630. Tomorrow I'll check it > against r270639 (seeking support). Indeed the issue is still present as of this patch on top of r270667.
Peng Liu
Comment 16 2020-12-11 09:46:48 PST
(In reply to Lauro Moura from comment #15) > (In reply to Lauro Moura from comment #14) > > This investigation was done on top of r270630. Tomorrow I'll check it > > against r270639 (seeking support). > > > Indeed the issue is still present as of this patch on top of r270667. I guess we can land the current patch first and file a new bug to track the seeking issue. What do you think?
Lauro Moura
Comment 17 2020-12-11 22:05:18 PST
Created attachment 416090 [details] Patch with updated expectations Updated the expectations and opened bug219822 for the new failures.
EWS
Comment 18 2020-12-13 02:26:42 PST
Tools/Scripts/svn-apply failed to apply attachment 416090 [details] to trunk. Please resolve the conflicts and upload a new patch.
Philippe Normand
Comment 19 2020-12-14 01:42:33 PST
EWS
Comment 20 2020-12-14 02:35:32 PST
Committed r270765: <https://trac.webkit.org/changeset/270765> All reviewed patches have been landed. Closing bug and clearing flags on attachment 416141 [details].
Radar WebKit Bug Importer
Comment 21 2020-12-14 02:36:20 PST
Note You need to log in before you can comment on or make changes to this bug.