Bug 213857 – REGRESSION(r260755): [GStreamer] Crash in webKitWebSrcCreate

• Component: Media
• Status: RESOLVED FIXED

[Michael Catanzaro]

Load https://www.bloomberg.com/news/articles/2020-06-15/so-is-tesla-bigger-than-toyota-or-not-well-it-s-complicated in Tech Preview (currently using 2.29.2) and scroll up and down for a little bit. After a few seconds, it will crash on     RELEASE_ASSERT(members->player) in webKitWebSrcCreate:

(gdb) bt full
#0  0x00007fb12220da15 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
        set = 
            {__val = {0, 140398714206252, 206158430248, 140398714278715, 140285325600448, 140287322131040, 140286651102816, 140398754970704, 140286516863248, 55, 140286516796992, 140398754074212, 32, 140286516796992, 0, 0}}
        pid = <optimized out>
        tid = <optimized out>
#1  0x00007fb1221f6855 in __GI_abort () at abort.c:79
        save_stage = 1
        act = 
          {__sigaction_handler = {sa_handler = 0x20, sa_sigaction = 0x20}, sa_mask = {__val = {32, 140285241731848, 47, 94921742113184, 140398754074212, 140285218762752, 95, 140285107519344, 140398754074212, 140285218762752, 140285325601056, 140285325601136, 140286516884192, 140286516884192, 140398775357722, 0}}, sa_flags = -666304256, sa_restorer = 0x7f9700017148}
        sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x00007fb122aead32 in CRASH_WITH_INFO(...) () at DerivedSources/ForwardingHeaders/wtf/Assertions.h:713
        baseSrc = 0x7f97000172e0 [WebKitWebSrc]
        src = <optimized out>
        priv = <optimized out>
        members = 
          {m_mutex = @0x7f9700017140, m_lockHolder = {<WTF::AbstractLocker> = {<No data fields>}, m_lockable = 0x7f9700017140}, m_data = @0x7f9700017148}
        __FUNCTION__ = "webKitWebSrcCreate"
        size = <optimized out>
        queueSize = <optimized out>
#3  0x00007fb122aead32 in webKitWebSrcCreate(GstPushSrc*, GstBuffer**)
    (pushSrc=0x7f97000172e0 [WebKitWebSrc], buffer=0x7f96b8ffea38)
    at ../Source/WebCore/platform/graphics/gstreamer/WebKitWebSourceGStreamer.cpp:483
        baseSrc = 0x7f97000172e0 [WebKitWebSrc]
        src = <optimized out>
        priv = <optimized out>
        members = 
          {m_mutex = @0x7f9700017140, m_lockHolder = {<WTF::AbstractLocker> = {<No data fields>}, m_lockable = 0x7f9700017140}, m_data = @0x7f9700017148}
        __FUNCTION__ = "webKitWebSrcCreate"
        size = <optimized out>
        queueSize = <optimized out>
#4  0x00007fb11f9160fd in gst_base_src_get_range
    (src=src@entry=0x7f97000172e0 [WebKitWebSrc], offset=offset@entry=0, length=<optimized out>, buf=buf@entry=0x7f96b8ffeb18) at ../libs/gst/base/gstbasesrc.c:2527
        ret = <optimized out>
        bclass = 0x5654b0ea3ca0
        status = <optimized out>
        res_buf = 0x0
        in_buf = 0x0
        own_res_buf = <optimized out>
        __func__ = "gst_base_src_get_range"
#5  0x00007fb11f919006 in gst_base_src_loop (pad=0x7f96ac00ad30 [GstPad]) at ../libs/gst/base/gstbasesrc.c:2851
        src = 0x7f97000172e0 [WebKitWebSrc]
        buf = 0x0
        ret = <optimized out>
        position = <optimized out>
        eos = 0
        blocksize = <optimized out>
        pending_events = 0x0
        tmp = <optimized out>
        __func__ = "gst_base_src_loop"
#6  0x00007fb11f849307 in gst_task_func (task=0x7f97000094d0 [GstTask]) at ../gst/gsttask.c:328
        lock = 0x7f96ac00ada0
        tself = 0x7f97000028c0
        priv = 0x7f9700009480
        __func__ = "gst_task_func"
#7  0x00007fb121ddc564 in g_thread_pool_thread_proxy (data=<optimized out>) at ../glib/gthreadpool.c:354
        task = 0x7f9700001490
        pool = <optimized out>
#8  0x00007fb121ddbc61 in g_thread_proxy (data=0x7f97000028c0) at ../glib/gthread.c:819
        thread = 0x7f97000028c0
        __func__ = "g_thread_proxy"
#9  0x00007fb11fdae4d2 in start_thread (arg=<optimized out>) at pthread_create.c:477
        ret = <optimized out>
        pd = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140285325604608, 2516772936556526736, 140286747463678, 140286747463679, 140285325602112, 94921751437184, -2467921634287895408, -2481659232919307120}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = 0
#10 0x00007fb1222d2563 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

[Alicia Boya García]

Do you have a coredump? Could you print ((GstObject*)0x7f97000172e0)->parent?

[Michael Catanzaro]

Sure:

(gdb) print ((GstObject*)0x7f97000172e0)->parent
$1 = 0x0

[Alicia Boya García]

That means the WebKitMediaSrc was not part of a pipeline by the time it tried to query the pipeline for a player. Querying who is the player is necessary so network requests are made from the correct origin.

I know there are cases where adaptivedemux operates an HTTP source unlinked from the rest of the pipeline, but it's especially problematic if it's used before ever having found its player...

[Michael Catanzaro]

I'm pretty sure this is a regression, because I can't reproduce in system Epiphany with WebKitGTK 2.28.3. This would be a good one to resolve before 2.30.

[Michael Catanzaro]

This seems to be a very common crasher in 2.30 that would be good to diagnose further....

[Philippe Normand]

Please include logs, as I can't reproduce this here...
GST_DEBUG_FILE=gst.log GST_DEBUG="3,webkit*:6"

[Michael Catanzaro]

Hm, seems it sometimes crashes almost immediately, and other times requires scrolling up and down for as much as 15-20 seconds. But it always crashes for me in Tech Preview.

Is there some environment variable to turn off terminal control codes? I'll attach the full log, but it's hard to read with all those control codes. The most interesting portion is the first and last line:

0:00:00.073135266 [334m  237[00m 0x55a1dc127750 [37mDEBUG  [00m [00m   webkitmediaplayer MediaPlayerPrivateGStreamer.cpp:2691:supportsType:[00m Checking mime-type "image/svg+xml"

Then there's a bunch of debug from GStreamerRegistryScanner.cpp. Then:

0:00:00.074495829 [334m  237[00m 0x55a1dc127750 [37mDEBUG  [00m [00m   webkitmediaplayer MediaPlayerPrivateGStreamer.cpp:2696:supportsType:[00m Supported: IsNotSupported

Asking GStreamer to play an SVG seems weird. Could it be related to video in image tags?

[Michael Catanzaro]

Created attachment 411159 [details]
gst.log (not much here)

[Michael Catanzaro]

Well guess what. The crash I am seeing is not even the original crash. The same webpage now produces a different WebKitWebSrc crash. I'm tempted to create a new bug report for a new crash, but... well, it's the same webpage, and the same WebKitWebSrc code, so *shrug* I'll just dump it here:

(gdb) bt full
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
        set = 
            {__val = {0, 12782710909496741120, 139995894889756, 12782710909496741120, 139985458026176, 139985332214784, 139995895249264, 0, 139985869280816, 0, 139988762315664, 139995894401087, 139995894889756, 139985458026240, 206158430256, 139985458026472}}
        pid = <optimized out>
        tid = <optimized out>
#1  0x00007f53582cc855 in __GI_abort () at abort.c:79
        save_stage = 1
        act = 
          {__sigaction_handler = {sa_handler = 0x20, sa_sigaction = 0x20}, sa_mask = {__val = {32, 139985197995176, 47, 93923871817120, 139995933958724, 139988091830272, 95, 139985332220464, 139995933958724, 139988091830272, 139985458026784, 139985458026864, 139985466489296, 139985466489296, 139995955403882, 0}}, sa_flags = -1290777344, sa_restorer = 0x7f50e800f838}
        sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x00007f5358bc9896 in webKitWebAudioSrcLoop(_WebKitWebAudioSrc*) [clone .cold] ()
    at /usr/lib/x86_64-linux-gnu/libwebkit2gtk-4.0.so.37
#3  0x00007f53559f70fd in gst_base_src_get_range
    (src=src@entry=0x7f50e800f9d0 [WebKitWebSrc], offset=offset@entry=0, length=<optimized out>, buf=buf@entry=0x7f50e77fdb18) at ../libs/gst/base/gstbasesrc.c:2527
        ret = <optimized out>
        bclass = 0x556c5b401400
        status = <optimized out>
        res_buf = 0x0
        in_buf = 0x0
        own_res_buf = <optimized out>
        __func__ = "gst_base_src_get_range"
#4  0x00007f53559fa006 in gst_base_src_loop (pad=0x7f50e000ac30 [GstPad]) at ../libs/gst/base/gstbasesrc.c:2851
        src = 0x7f50e800f9d0 [WebKitWebSrc]
        buf = 0x0
        ret = <optimized out>
        position = <optimized out>
        eos = 0
        blocksize = <optimized out>
        pending_events = 0x0
        tmp = <optimized out>
        __func__ = "gst_base_src_loop"
#5  0x00007f5355929f57 in gst_task_func (task=0x556c5b739ef0 [GstTask]) at ../gst/gsttask.c:328
        lock = 0x7f50e000aca0
        tself = 0x7f50e8001860
        priv = 0x556c5b739ea0
        __func__ = "gst_task_func"
#6  0x00007f5357ea99c4 in g_thread_pool_thread_proxy (data=<optimized out>) at ../glib/gthreadpool.c:354
        task = 0x556c5b34f810
        pool = <optimized out>
#7  0x00007f5357ea90b1 in g_thread_proxy (data=0x7f50e8001860) at ../glib/gthread.c:820
        thread = 0x7f50e8001860
        __func__ = "g_thread_proxy"
#8  0x00007f5355e9c4d2 in start_thread (arg=<optimized out>) at pthread_create.c:477
        ret = <optimized out>
        pd = <optimized out>
        unwind_buf = 
              {cancel_jmp_buf = {{jmp_buf = {139985458030336, -1145297083979449341, 139988117200894, 139988117200895, 139985458027840, 8396800, 1061398850249243651, 1062213501568629763}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = 0
#9  0x00007f53583a84d3 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

[Philippe Normand]

(In reply to Michael Catanzaro from comment #7)
> Hm, seems it sometimes crashes almost immediately, and other times requires
> scrolling up and down for as much as 15-20 seconds. But it always crashes
> for me in Tech Preview.
> 
> Is there some environment variable to turn off terminal control codes?

GST_DEBUG_NO_COLOR=1

> I'll
> attach the full log, but it's hard to read with all those control codes. The
> most interesting portion is the first and last line:
> 
> 0:00:00.073135266 [334m  237[00m 0x55a1dc127750 [37mDEBUG  [00m [00m  
> webkitmediaplayer MediaPlayerPrivateGStreamer.cpp:2691:supportsType:[00m
> Checking mime-type "image/svg+xml"
> 
> Then there's a bunch of debug from GStreamerRegistryScanner.cpp. Then:
> 
> 0:00:00.074495829 [334m  237[00m 0x55a1dc127750 [37mDEBUG  [00m [00m  
> webkitmediaplayer MediaPlayerPrivateGStreamer.cpp:2696:supportsType:[00m
> Supported: IsNotSupported
> 
> Asking GStreamer to play an SVG seems weird. Could it be related to video in
> image tags?

Could be yes, but I don't think it's relevant here...

New trace doesn't make sense, what does webKitWebAudioSrcLoop do in frame 2???

[Michael Catanzaro]

(In reply to Philippe Normand from comment #10)
> New trace doesn't make sense, what does webKitWebAudioSrcLoop do in frame
> 2???

Hmm, I wonder why that frame is missing. Looks like that's the only WebKit frame in the backtrace... but WebKit is part of the runtime, so it's the same .Debug extension as all the GStreamer frames, I'm not sure how debuginfo could be present for one but not the other. Odd.

Anyway, I can reproduce without using flatpak, so I decided to get a backtrace there, hoping it would show the missing frame. Instead, it is a *third* crash involving WebKitWebSrc. Again, all I do is load the page and scroll up and down:

#0  0x00007f2991fcbbde in WTFCrash ()
    at ../../Source/WTF/wtf/Assertions.cpp:295
No locals.
#1  0x00007f29943d3710 in CRASH_WITH_INFO(...) ()
    at DerivedSources/ForwardingHeaders/wtf/Assertions.h:713
No locals.
#2  webKitWebSrcCreate (pushSrc=0x3a772b0 [WebKitWebSrc|webkitwebsrc6], 
    buffer=0x7f28d9afe888)
    at ../../Source/WebCore/platform/graphics/gstreamer/WebKitWebSourceGStreamer.cpp:483
        baseSrc = 0x3a772b0 [WebKitWebSrc|webkitwebsrc6]
        src = <optimized out>
        priv = <optimized out>
        members = {m_mutex = @0x3a77110, 
          m_lockHolder = {<WTF::AbstractLocker> = {<No data fields>}, 
            m_lockable = 0x3a77110}, m_data = @0x3a77118}
        __FUNCTION__ = "webKitWebSrcCreate"
        size = <optimized out>
        queueSize = <optimized out>
#3  0x00007f298e68880d in gst_base_src_get_range ()
   from /lib64/libgstbase-1.0.so.0
No symbol table info available.
#4  0x00007f298e68f3c2 in gst_base_src_loop.lto_priv ()
   from /lib64/libgstbase-1.0.so.0
No symbol table info available.
#5  0x00007f298e5b454f in gst_task_func () from /lib64/libgstreamer-1.0.so.0
No symbol table info available.
#6  0x00007f298dcf1141 in g_thread_pool_thread_proxy (data=0x1e490e0) at ../../../../Projects/glib/glib/gthreadpool.c:354
        task = 0x1e192a0
        pool = 0x1e490e0
#7  0x00007f298dcf0a14 in g_thread_proxy (data=0x1e05d80) at ../../../../Projects/glib/glib/gthread.c:820
        thread = 0x1e05d80
        __func__ = "g_thread_proxy"
#8  0x00007f298dd2145a in linux_pthread_proxy (data=0x1e05d80) at ../../../../Projects/glib/glib/gthread-posix.c:1259
        thread = 0x1e05d80
        printed_scheduler_warning = 1
#9  0x00007f298ecb63f9 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#10 0x00007f298cc9bb03 in clone () from /lib64/libc.so.6
No symbol table info available.

So that's three different WebKitWebSrc crashes. I'm starting to suspect a threadsafety issue, perhaps? I see there are a couple dozen threads running GStreamer code at the same time (will attach a 'thread apply all bt'), which is more than I would expect.

[Michael Catanzaro]

Created attachment 411219 [details]
'thread apply all bt' corresponding to comment 11

It's missing gstreamer debuginfo unfortunately. I suspect a Fedora bug there. That shouldn't happen.

[Michael Catanzaro]

Seems I can get you a flatpak backtrace without WebKit debuginfo, or a Fedora backtrace without GStreamer debuginfo. Something is broken either way. :S

[Xabier Rodríguez Calvar]

Fixed in r273731.