Bug 160131 – [GTK] Layout test media/track/track-in-band-duplicate-tracks-when-source-changes.html flaky again

• Component: Media
• Status: RESOLVED FIXED

[Michael Catanzaro]

Layout test media/track/track-in-band-duplicate-tracks-when-source-changes.html is sadly double-broken:

 * It has been flakily crashing for a very long time.
 * It has been flakily timing out since we enabled threaded compositor.

Lots of other tests are timing out too, so it's probably best to restrict this bug to the crash, but if the crash is fixed before the timeout is fixed then we need to reassign the test expectation to some other bug before closing this one.

[Michael Catanzaro]

Updating expectations accordingly.

[Ms2ger (he/him; ⌚ UTC+1/+2)]

It's crashing because mediaElement() is null in VideoTrack::setLanguage(). Not sure if this is something it should be expected to deal with, or if there's an underlying problem. (The billion-dollar mistake indeed.)

[Fujii Hironori]

GTK port, Debug build, trunk@225473

> Thread 1 (Thread 0x7f54e9eaca80 (LWP 123232)):
> #0  0x00007f54e45000dc in WTF::RefPtr<WebCore::VideoTrackList>::operator! (this=0x6d0) at ../../Source/WTF/wtf/RefPtr.h:81
> #1  0x00007f54e4d32073 in (anonymous namespace)::HTMLMediaElement::videoTracks (this=0x0) at ../../Source/WebCore/html/HTMLMediaElement.cpp:4079
> #2  0x00007f54e5b5537c in (anonymous namespace)::VideoTrack::setLanguage (this=0x7f547436c7e0, language=...) at ../../Source/WebCore/html/track/VideoTrack.cpp:213
> #3  0x00007f54e5b551eb in (anonymous namespace)::VideoTrack::languageChanged (this=0x7f547436c7e0, language=...) at ../../Source/WebCore/html/track/VideoTrack.cpp:161
> #4  0x00007f54e5e67858 in (anonymous namespace)::TrackPrivateBaseGStreamer::notifyTrackOfTagsChanged (this=0x7f547432a110) at ../../Source/WebCore/platform/graphics/gstreamer/TrackPrivateBaseGStreamer.cpp:172
> #5  0x00007f54e5e6729f in (anonymous namespace)::TrackPrivateBaseGStreamer::<lambda()>::operator()(void) const (__closure=0x7f5474321038) at ../../Source/WebCore/platform/graphics/gstreamer/TrackPrivateBaseGStreamer.cpp:103
> #6  0x00007f54e5e6988a in WTF::Function<void()>::CallableWrapper<WebCore::TrackPrivateBaseGStreamer::tagsChanged()::<lambda()> >::call(void) (this=0x7f5474321030) at ../../Source/WTF/wtf/Function.h:101
> #7  0x00007f54e2f0b4e6 in WTF::Function<void()>::operator()(void) const (this=0x7f54743230c0) at ../../Source/WTF/wtf/Function.h:56
> #8  0x00007f54e5e67b5a in (anonymous namespace)::MainThreadNotifier<WebCore::TrackPrivateBaseGStreamer::MainThreadNotification>::<lambda()>::operator()(void) const (__closure=0x7f54743230a8) at ../../Source/WebCore/platform/graphics/gstreamer/MainThreadNotifier.h:55
> #9  0x00007f54e5e6986c in WTF::Function<void()>::CallableWrapper<WebCore::MainThreadNotifier<T>::notify(T, F&&) [with F = WebCore::TrackPrivateBaseGStreamer::tagsChanged()::<lambda()>; T = WebCore::TrackPrivateBaseGStreamer::MainThreadNotification]::<lambda()> >::call(void) (this=0x7f54743230a0) at ../../Source/WTF/wtf/Function.h:101
> #10 0x00007f54e2f0b4e6 in WTF::Function<void()>::operator()(void) const (this=0x7ffd69da9380) at ../../Source/WTF/wtf/Function.h:56
> #11 0x00007f54d8bbf3dd in WTF::RunLoop::performWork (this=0x7f54c75fc100) at ../../Source/WTF/wtf/RunLoop.cpp:106
> #12 0x00007f54d8c0f3b6 in WTF::RunLoop::<lambda(gpointer)>::operator()(gpointer) const (__closure=0x0, userData=0x7f54c75fc100) at ../../Source/WTF/wtf/glib/RunLoopGLib.cpp:68
> #13 0x00007f54d8c0f3da in WTF::RunLoop::<lambda(gpointer)>::_FUN(gpointer) () at ../../Source/WTF/wtf/glib/RunLoopGLib.cpp:70
> #14 0x00007f54d8c0f356 in WTF::<lambda(GSource*, GSourceFunc, gpointer)>::operator()(GSource *, GSourceFunc, gpointer) const (__closure=0x0, source=0x560fb0946af0, callback=0x7f54d8c0f3bd <WTF::RunLoop::<lambda(gpointer)>::_FUN(gpointer)>, userData=0x7f54c75fc100) at ../../Source/WTF/wtf/glib/RunLoopGLib.cpp:45
> #15 0x00007f54d8c0f385 in WTF::<lambda(GSource*, GSourceFunc, gpointer)>::_FUN(GSource *, GSourceFunc, gpointer) () at ../../Source/WTF/wtf/glib/RunLoopGLib.cpp:46
> #16 0x00007f54d9db6c35 in g_main_dispatch () at /home/fujii/work/webkit/ga/WebKitBuild/DependenciesGTK/Source/glib-2.54.2/glib/gmain.c:3148
> #17 g_main_context_dispatch () at /home/fujii/work/webkit/ga/WebKitBuild/DependenciesGTK/Source/glib-2.54.2/glib/gmain.c:3813
> #18 0x00007f54d9db7000 in g_main_context_iterate () at /home/fujii/work/webkit/ga/WebKitBuild/DependenciesGTK/Source/glib-2.54.2/glib/gmain.c:3886
> #19 0x00007f54d9db7312 in g_main_loop_run () at /home/fujii/work/webkit/ga/WebKitBuild/DependenciesGTK/Source/glib-2.54.2/glib/gmain.c:4082
> #20 0x00007f54d8c0f8d5 in WTF::RunLoop::run () at ../../Source/WTF/wtf/glib/RunLoopGLib.cpp:96
> #21 0x00007f54e3820996 in (anonymous namespace)::ChildProcessMain<WebKit::WebProcess, WebKit::WebProcessMain> (argc=2, argv=0x7ffd69da9778) at ../../Source/WebKit/Shared/unix/ChildProcessMain.h:61
> #22 0x00007f54e3820839 in (anonymous namespace)::WebProcessMainUnix (argc=2, argv=0x7ffd69da9778) at ../../Source/WebKit/WebProcess/gtk/WebProcessMainGtk.cpp:69
> #23 0x0000560faebe9a45 in main (argc=2, argv=0x7ffd69da9778) at ../../Source/WebKit/WebProcess/EntryPoint/unix/WebProcessMain.cpp:52

[Fujii Hironori]

This is the callstack when the m_mediaElement is cleared.

> #0  (anonymous namespace)::VideoTrack::setMediaElement (this=0x7f6ec91ffaf0, element=0x0) at ../../Source/WebCore/html/track/VideoTrack.cpp:248
> #1  0x00007f6f4a26018f in (anonymous namespace)::TrackListBase::remove (this=0x7f6eca7343e0, track=..., scheduleEvent=true)
>     at ../../Source/WebCore/html/track/TrackListBase.cpp:79
> #2  0x00007f6f49447ae1 in (anonymous namespace)::HTMLMediaElement::removeVideoTrack (this=0x7f6eca766800, track=...)
>     at ../../Source/WebCore/html/HTMLMediaElement.cpp:4006
> #3  0x00007f6f49447cb4 in (anonymous namespace)::HTMLMediaElement::forgetResourceSpecificTracks (this=0x7f6eca766800)
>     at ../../Source/WebCore/html/HTMLMediaElement.cpp:4025
> #4  0x00007f6f4944f016 in (anonymous namespace)::HTMLMediaElement::createMediaPlayer (this=0x7f6eca766800) at ../../Source/WebCore/html/HTMLMediaElement.cpp:6410
> #5  0x00007f6f4943f388 in (anonymous namespace)::HTMLMediaElement::loadNextSourceChild (this=0x7f6eca766800) at ../../Source/WebCore/html/HTMLMediaElement.cpp:1527
> #6  0x00007f6f4943dd5f in (anonymous namespace)::HTMLMediaElement::<lambda()>::operator()(void) const (__closure=0x7f6ec91c58b8)
>     at ../../Source/WebCore/html/HTMLMediaElement.cpp:1054
> #7  0x00007f6f49458fd2 in WTF::Function<void()>::CallableWrapper<WebCore::HTMLMediaElement::scheduleNextSourceChild()::<lambda()> >::call(void) (
>     this=0x7f6ec91c58b0) at ../../Source/WTF/wtf/Function.h:101
> #8  0x00007f6f476214e6 in WTF::Function<void()>::operator()(void) const (this=0x7f6ebf0dfef8) at ../../Source/WTF/wtf/Function.h:56
> #9  0x00007f6f48dc6591 in (anonymous namespace)::GenericTaskQueue<WebCore::Timer>::<lambda()>::operator()(void) const (__closure=0x7f6ebf0dfef0)
>     at ../../Source/WebCore/platform/GenericTaskQueue.h:96
> #10 0x00007f6f48dd0798 in WTF::Function<void()>::CallableWrapper<WebCore::GenericTaskQueue<T>::enqueueTask(WebCore::GenericTaskQueue<T>::TaskFunction&&) [with T = WebCore::Timer; WebCore::GenericTaskQueue<T>::TaskFunction = WTF::Function<void()>]::<lambda()> >::call(void) (this=0x7f6ebf0dfee8)
>     at ../../Source/WTF/wtf/Function.h:101
> #11 0x00007f6f476214e6 in WTF::Function<void()>::operator()(void) const (this=0x7ffca0b6a440) at ../../Source/WTF/wtf/Function.h:56
> #12 0x00007f6f4997277e in (anonymous namespace)::TaskDispatcher<WebCore::Timer>::dispatchOneTask (this=0x7f6eca766c10)
>     at ../../Source/WebCore/platform/GenericTaskQueue.cpp:80
> #13 0x00007f6f49972649 in (anonymous namespace)::TaskDispatcher<WebCore::Timer>::sharedTimerFired () at ../../Source/WebCore/platform/GenericTaskQueue.cpp:65
> #14 0x00007f6f499724a3 in (anonymous namespace)::TaskDispatcher<WebCore::Timer>::<lambda()>::operator()(void) const (__closure=0x7f6eca776958)
>     at ../../Source/WebCore/platform/GenericTaskQueue.cpp:49
> #15 0x00007f6f4997308e in WTF::Function<void()>::CallableWrapper<WebCore::TaskDispatcher<WebCore::Timer>::sharedTimer()::<lambda()> >::call(void) (
>     this=0x7f6eca776950) at ../../Source/WTF/wtf/Function.h:101
> #16 0x00007f6f476214e6 in WTF::Function<void()>::operator()(void) const (this=0x7f6f4e3ef740 <WebCore::TaskDispatcher<WebCore::Timer>::sharedTimer()::timer+64>)
>     at ../../Source/WTF/wtf/Function.h:56
> #17 0x00007f6f4762d172 in (anonymous namespace)::Timer::fired (this=0x7f6f4e3ef700 <WebCore::TaskDispatcher<WebCore::Timer>::sharedTimer()::timer>)
>     at ../../Source/WebCore/platform/Timer.h:133
> #18 0x00007f6f4999c075 in (anonymous namespace)::ThreadTimers::sharedTimerFiredInternal (this=0x7f6f29efd1e0) at ../../Source/WebCore/platform/ThreadTimers.cpp:118
> #19 0x00007f6f4999bb4d in (anonymous namespace)::ThreadTimers::<lambda()>::operator()(void) const (__closure=0x7f6f29efa378)
>     at ../../Source/WebCore/platform/ThreadTimers.cpp:70
> #20 0x00007f6f4999e9c0 in WTF::Function<void()>::CallableWrapper<WebCore::ThreadTimers::setSharedTimer(WebCore::SharedTimer*)::<lambda()> >::call(void) (
>     this=0x7f6f29efa370) at ../../Source/WTF/wtf/Function.h:101
> #21 0x00007f6f476214e6 in WTF::Function<void()>::operator()(void) const (this=0x7f6f4e3ef868 <WebCore::MainThreadSharedTimer::singleton()::instance+8>)
>     at ../../Source/WTF/wtf/Function.h:56
> #22 0x00007f6f499831e9 in (anonymous namespace)::MainThreadSharedTimer::fired (this=0x7f6f4e3ef860 <WebCore::MainThreadSharedTimer::singleton()::instance>)
>     at ../../Source/WebCore/platform/MainThreadSharedTimer.cpp:54
> #23 0x00007f6f499846a0 in WTF::RunLoop::Timer<WebCore::MainThreadSharedTimer>::fired (
>     this=0x7f6f4e3ef870 <WebCore::MainThreadSharedTimer::singleton()::instance+16>) at ../../Source/WTF/wtf/RunLoop.h:152
> #24 0x00007f6f3d350c91 in WTF::RunLoop::TimerBase::<lambda(gpointer)>::operator()(gpointer) const (__closure=0x0, 
>     userData=0x7f6f4e3ef870 <WebCore::MainThreadSharedTimer::singleton()::instance+16>) at ../../Source/WTF/wtf/glib/RunLoopGLib.cpp:166
> #25 0x00007f6f3d350ccd in WTF::RunLoop::TimerBase::<lambda(gpointer)>::_FUN(gpointer) () at ../../Source/WTF/wtf/glib/RunLoopGLib.cpp:170
> #26 0x00007f6f3d350356 in WTF::<lambda(GSource*, GSourceFunc, gpointer)>::operator()(GSource *, GSourceFunc, gpointer) const (__closure=0x0, 
>     source=0x564f612caa30, callback=0x7f6f3d350cb0 <WTF::RunLoop::TimerBase::<lambda(gpointer)>::_FUN(gpointer)>, 
>     userData=0x7f6f4e3ef870 <WebCore::MainThreadSharedTimer::singleton()::instance+16>) at ../../Source/WTF/wtf/glib/RunLoopGLib.cpp:45
> #27 0x00007f6f3d350385 in WTF::<lambda(GSource*, GSourceFunc, gpointer)>::_FUN(GSource *, GSourceFunc, gpointer) () at ../../Source/WTF/wtf/glib/RunLoopGLib.cpp:46
> #28 0x00007f6f3e4f7c35 in g_main_dispatch () at /home/fujii/work/webkit/ga/WebKitBuild/DependenciesGTK/Source/glib-2.54.2/glib/gmain.c:3148
> #29 g_main_context_dispatch () at /home/fujii/work/webkit/ga/WebKitBuild/DependenciesGTK/Source/glib-2.54.2/glib/gmain.c:3813
> #30 0x00007f6f3e4f8000 in g_main_context_iterate () at /home/fujii/work/webkit/ga/WebKitBuild/DependenciesGTK/Source/glib-2.54.2/glib/gmain.c:3886
> #31 0x00007f6f3e4f8312 in g_main_loop_run () at /home/fujii/work/webkit/ga/WebKitBuild/DependenciesGTK/Source/glib-2.54.2/glib/gmain.c:4082
> #32 0x00007f6f3d3508d5 in WTF::RunLoop::run () at ../../Source/WTF/wtf/glib/RunLoopGLib.cpp:96
> #33 0x00007f6f47f36996 in (anonymous namespace)::ChildProcessMain<WebKit::WebProcess, WebKit::WebProcessMain> (argc=2, argv=0x7ffca0b6a9e8)
>     at ../../Source/WebKit/Shared/unix/ChildProcessMain.h:61
> #34 0x00007f6f47f36839 in (anonymous namespace)::WebProcessMainUnix (argc=2, argv=0x7ffca0b6a9e8) at ../../Source/WebKit/WebProcess/gtk/WebProcessMainGtk.cpp:69
> #35 0x0000564f60461a45 in main (argc=2, argv=0x7ffca0b6a9e8) at ../../Source/WebKit/WebProcess/EntryPoint/unix/WebProcessMain.cpp:52

[Fujii Hironori]

VideoTrack::willRemove() already has a null check of m_mediaElement.
This was added by Darin Adler in Bug 166635.

InbandTextTrack::willRemove() also has the null check.
This was added by Eric Carlson in Bug 117938.

But, AudioTrack::willRemove() doesn't have the null check even
though it also dereference the m_mediaElement.

[Fujii Hironori]

Created attachment 328431 [details]
WIP patch

* This patch doesn't solve the time-out issue.

[Fujii Hironori]

I can reproduce the timeout bug by repeatedly reloading the test case media/track/track-in-band-duplicate-tracks-when-source-changes.html in GTK MiniBrowser.

This test case expects two canplaythrough events are dispatched.
There are two types of timeout failure.

1. No canplaythrough event dispatched.
2. Only one canplaythrough event dispatched.

Screenshots: https://photos.app.goo.gl/avRU9ubausB0pQrs2

[Fujii Hironori]

Created attachment 328549 [details]
Patch

* Fixing only the crash issue

[WebKit Commit Bot]

Comment on attachment 328549 [details]
Patch

Clearing flags on attachment: 328549

Committed r225567: <https://trac.webkit.org/changeset/225567>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.

[Fujii Hironori]

Reopened. The timeout issue still occurs.

[Radar WebKit Bug Importer]

<rdar://problem/35873985>

[Fujii Hironori]

MediaPlayerPrivateGStreamer::loadingFailed was called in case of the timeout issues happened.

[Claudio Saavedra]

This is now failing consistently after https://trac.webkit.org/changeset/228617:

--- /home/slave/webkitgtk/gtk-linux-64-release-tests/build/layout-test-results/media/track/track-in-band-duplicate-tracks-when-source-changes-expected.txt
+++ /home/slave/webkitgtk/gtk-linux-64-release-tests/build/layout-test-results/media/track/track-in-band-duplicate-tracks-when-source-changes-actual.txt
@@ -4,7 +4,7 @@
 EVENT(canplaythrough)
 
 ** Storing number of tracks and reloading video
-EXPECTED (video.textTracks.length > '0') OK
+EXPECTED (video.textTracks.length > '0'), OBSERVED '0' FAIL
 RUN(numTracks = video.textTracks.length)
 EVENT(canplaythrough)

[Philippe Normand]

(In reply to Fujii Hironori from comment #13)
> MediaPlayerPrivateGStreamer::loadingFailed was called in case of the timeout
> issues happened.

Seems a bit odd because that patch shouldn't have a functional impact unless playbin3 is enabled, which isn't the case... I'll try to debug it at some point if time allows...

[Philippe Normand]

Created attachment 334267 [details]
Patch

[Michael Catanzaro]

Comment on attachment 334267 [details]
Patch

Aren't there test expectations to update too?

[Philippe Normand]

It seems Claudio didn't update it? I haven't touched it because I assume the test will be flaky again, as before I broke it for real.

[Philippe Normand]

Committed r228868 but leaving bug open as the test might still be flaky.

[Claudio Saavedra]

It's still flaky, it timed out a few times but it's passing most times now. Thanks Phil!

[Diego Pino]

This test, or group of tests, has been passing for the last 4000 revisions. Closing bug. Gardened in r278519.