Bug 247057

FWIW it's easy to reproduce and a lot of users are complaining, so you're not alone.

I haven't investigated this, but the most likely explanation is a file descriptor leak somewhere causing the IPC socket to not be fully closed.

(In reply to Michael Catanzaro from comment #1)
> FWIW it's easy to reproduce

Actually I just assumed this (due to the number of complaints) without investigating first. Unfortunately I am not able to reproduce.

(In reply to Michael Catanzaro from comment #1)
> I haven't investigated this, but the most likely explanation is a file
> descriptor leak somewhere causing the IPC socket to not be fully closed.

I was completely wrong. What's happening is the web process is hanging. I'm certain that there are multiple different bugs causing this to happen, but will use this bug for the most prominent such issue. We can report new bugs as we find more.

The UI process never kills web processes itself; instead, it relies on the web processes to quit themselves after they notice a HUP event on their IPC socket connected to the UI process. If the web process gets hung such that it never returns to the main loop (does not iterate the default main context), then the web process will stay alive forever and never quit.

I think prctl(PR_SET_PDEATHSIG) might suffice to ensure subprocesses are definitely killed when the UI process exits, but that's Linux-specific. Alternatively, the UI process itself could manually kill subprocesses when it exists. To be even more robust, we could add a new subprocess type to do the killing, so we don't leak subprocesses even if the web process has hung *and* the UI process has crashed. That might be an unnecessary level of paranoia, though.

We need to fix the hangs regardless. I've been frustrated by frequent web process hangs during general browsing without having previously associated them with the issue of web process leaks. They're probably caused by a few of the same underlying problems. Anyway, all of the above is just some general thoughts on robustness; we don't need to change any of that to fix this bug. For this bug, let's fix address the most prominent web process leak that I've noticed. I've retitled this bug accordingly; we can report more bugs if we discover further leaks. Here is a backtrace taken by manually sending SIGABRT to a web process that I noticed had been leaked:

(gdb) bt
#0  __futex_abstimed_wait_common64
    (private=0, cancel=true, abstime=0x0, op=393, expected=0, futex_word=0x7f88ca008364) at futex-internal.c:57
#1  __futex_abstimed_wait_common
    (futex_word=futex_word@entry=0x7f88ca008364, expected=expected@entry=0, clockid=clockid@entry=0, abstime=abstime@entry=0x0, private=private@entry=0, cancel=cancel@entry=true) at futex-internal.c:87
#2  0x00007f88ea28bc1f in __GI___futex_abstimed_wait_cancelable64
    (futex_word=futex_word@entry=0x7f88ca008364, expected=expected@entry=0, clockid=clockid@entry=0, abstime=abstime@entry=0x0, private=private@entry=0) at futex-internal.c:139
#3  0x00007f88ea28e4d1 in __pthread_cond_wait_common
    (abstime=0x0, clockid=0, mutex=<optimized out>, cond=0x7f88ca008338) at pthread_cond_wait.c:503
#4  ___pthread_cond_wait (cond=0x7f88ca008338, mutex=<optimized out>) at pthread_cond_wait.c:618
#5  0x00007f88e9cf754b in WTF::ThreadCondition::timedWait(WTF::Mutex&, WTF::WallTime)
    (this=this@entry=0x7f88ca008338, mutex=..., absoluteTime=...)
    at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WTF/wtf/posix/ThreadingPOSIX.cpp:613
#6  0x00007f88e9c8e663 in WTF::ParkingLot::parkConditionallyImpl(void const*, WTF::ScopedLambda<bool ()> const&, WTF::ScopedLambda<void ()> const&, WTF::TimeWithDynamicClockType const&)
    (address=address@entry=0x7f880eb3fb28, validation=..., beforeSleep=..., timeout=...)
    at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WTF/wtf/ParkingLot.cpp:595
#7  0x00007f88eb4ca763 in WTF::ParkingLot::parkConditionally<WTF::Condition::waitUntilUnchecked<WTF::Lock>(WTF::Lock&, WTF::TimeWithDynamicClockType const&)::{lambda()#1}, WTF::Condition::waitUntilUnchecked<WTF::Lock>(WTF::Lock&, WTF::TimeWithDynamicClockType const&)::{lambda()#2}>(void const*, WTF::Condition::waitUntilUnchecked<WTF::Lock>(WTF::Lock&, WTF::TimeWithDynamicClockType const&)::{lambda()#1} const&, WTF::Condition::waitUntilUnchecked<WTF::Lock>(WTF::Lock&, WTF::TimeWithDynamicClockType const&)::{lambda()#2} const&, WTF::TimeWithDynamicClockType const&)
    (timeout=..., beforeSleep=..., validation=..., address=0x7f880eb3fb28)
    at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/_builddir/WTF/Headers/wtf/ScopedLambda.h:49
#8  WTF::Condition::waitUntilUnchecked<WTF::Lock>(WTF::Lock&, WTF::TimeWithDynamicClockType const&)
    (timeout=..., lock=..., this=0x7f880eb3fb28)
    at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/_builddir/WTF/Headers/wtf/Condition.h:192
#9  WTF::Condition::waitUntil(WTF::Lock&, WTF::TimeWithDynamicClockType const&)
    (timeout=..., lock=..., this=0x7f880eb3fb28)
    at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/_builddir/WTF/Headers/wtf/Condition.h:77
#10 WTF::Condition::wait(WTF::Lock&) (lock=..., this=0x7f880eb3fb28)
    at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/_builddir/WTF/Headers/wtf/Condition.h:127
#11 WebCore::ImageDecoderGStreamer::pushEncodedData(WebCore::FragmentedSharedBuffer const&)
    (this=0x7f880eb3fa80, buffer=<optimized out>)
    at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebCore/platform/graphics/gstreamer/ImageDecoderGStreamer.cpp:446
#12 0x00007f88eb4cac27 in WebCore::ImageDecoderGStreamer::create(WebCore::FragmentedSharedBuffer&, WTF::String const&, WebCore::AlphaOption, WebCore::GammaAndColorProfileOption)
    (data=..., mimeType=..., alphaOption=alphaOption@entry=WebCore::AlphaOption::Premultiplied, gammaAndColorProfileOption=gammaAndColorProfileOption@entry=WebCore::GammaAndColorProfileOption::Applied)
    at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebCore/platform/graphics/gstreamer/ImageDecoderGStreamer.cpp:86
#13 0x00007f88ece0d0b4 in WebCore::ImageDecoder::create(WebCore::FragmentedSharedBuffer&, WTF::String const&, WebCore::AlphaOption, WebCore::GammaAndColorProfileOption)
    (data=..., mimeType=..., alphaOption=alphaOption@entry=WebCore::AlphaOption::Premultiplied, gammaAndColorProfileOption=WebCore::GammaAndColorProfileOption::Applied)
    at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebCore/platform/graphics/ImageDecoder.cpp:105
#14 0x00007f88ece0fe71 in WebCore::ImageSource::ensureDecoderAvailable(WebCore::FragmentedSharedBuffer*)
    (this=this@entry=0x7f882466d080, data=data@entry=0x7f880e8d1680)
    at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebCore/platform/graphics/ImageSource.cpp:75
#15 0x00007f88ece108a3 in WebCore::ImageSource::setData(WebCore::FragmentedSharedBuffer*, bool)
--Type <RET> for more, q to quit, c to continue without paging--c
    (allDataReceived=<optimized out>, data=0x7f880e8d1680, this=0x7f882466d080) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebCore/platform/graphics/ImageSource.cpp:96
#16 WebCore::ImageSource::dataChanged(WebCore::FragmentedSharedBuffer*, bool) (this=0x7f882466d080, data=0x7f880e8d1680, allDataReceived=<optimized out>) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebCore/platform/graphics/ImageSource.cpp:110
#17 0x00007f88ecb74d35 in WebCore::CachedImage::updateImageData(bool) (this=this@entry=0x7f880ea53040, allDataReceived=allDataReceived@entry=false) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebCore/loader/cache/CachedImage.cpp:558
#18 0x00007f88ecb7ac8a in WebCore::CachedImage::updateBufferInternal(WebCore::FragmentedSharedBuffer const&) (this=0x7f880ea53040, data=<optimized out>) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebCore/loader/cache/CachedImage.cpp:510
#19 0x00007f88ecb4f6dd in WebCore::SubresourceLoader::didReceiveBuffer(WebCore::FragmentedSharedBuffer const&, long long, WebCore::DataPayloadType) (this=0x7f88182e4100, buffer=..., encodedDataLength=8704, dataPayloadType=WebCore::DataPayloadBytes) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebCore/loader/SubresourceLoader.cpp:562
#20 0x00007f88eb3b3ca7 in WebKit::WebResourceLoader::didReceiveData(IPC::SharedBufferReference&&, unsigned long) (this=this@entry=0x7f6fde6db360, data=..., encodedDataLength=8704) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebKit/WebProcess/Network/WebResourceLoader.cpp:243
#21 0x00007f88eae24cca in _ZZN3IPC18callMemberFunctionIN6WebKit17WebResourceLoaderES2_FvONS_21SharedBufferReferenceEmESt5tupleIJS3_mEEEEvPT_MT0_T1_OT2_ENKUlDpOT_E_clIJS3_mEEEDaSH_ (__closure=<optimized out>) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebKit/Platform/IPC/HandleMessage.h:133
#22 _ZSt13__invoke_implIvZN3IPC18callMemberFunctionIN6WebKit17WebResourceLoaderES3_FvONS0_21SharedBufferReferenceEmESt5tupleIJS4_mEEEEvPT_MT0_T1_OT2_EUlDpOT_E_JS4_mEES9_St14__invoke_otherOSB_DpOT1_ (__f=<optimized out>) at /usr/include/c++/12.1.0/bits/invoke.h:61
#23 _ZSt8__invokeIZN3IPC18callMemberFunctionIN6WebKit17WebResourceLoaderES3_FvONS0_21SharedBufferReferenceEmESt5tupleIJS4_mEEEEvPT_MT0_T1_OT2_EUlDpOT_E_JS4_mEENSt15__invoke_resultIS9_JDpT0_EE4typeEOS9_DpOSL_ (__fn=<optimized out>) at /usr/include/c++/12.1.0/bits/invoke.h:96
#24 _ZSt12__apply_implIZN3IPC18callMemberFunctionIN6WebKit17WebResourceLoaderES3_FvONS0_21SharedBufferReferenceEmESt5tupleIJS4_mEEEEvPT_MT0_T1_OT2_EUlDpOT_E_S8_JLm0ELm1EEEDcOS9_OSB_St16integer_sequenceImJXspT1_EEE (__t=..., __f=<optimized out>) at /usr/include/c++/12.1.0/tuple:1852
#25 _ZSt5applyIZN3IPC18callMemberFunctionIN6WebKit17WebResourceLoaderES3_FvONS0_21SharedBufferReferenceEmESt5tupleIJS4_mEEEEvPT_MT0_T1_OT2_EUlDpOT_E_S8_EDcOS9_OSB_ (__t=..., __f=<optimized out>) at /usr/include/c++/12.1.0/tuple:1863
#26 IPC::callMemberFunction<WebKit::WebResourceLoader, WebKit::WebResourceLoader, void (IPC::SharedBufferReference&&, unsigned long), std::tuple<IPC::SharedBufferReference, unsigned long> >(WebKit::WebResourceLoader*, void (WebKit::WebResourceLoader::*)(IPC::SharedBufferReference&&, unsigned long), std::tuple<IPC::SharedBufferReference, unsigned long>&&) (tuple=..., function=<optimized out>, object=<optimized out>) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebKit/Platform/IPC/HandleMessage.h:131
#27 IPC::handleMessage<Messages::WebResourceLoader::DidReceiveData, WebKit::WebResourceLoader, WebKit::WebResourceLoader, void (IPC::SharedBufferReference&&, unsigned long)>(IPC::Connection&, IPC::Decoder&, WebKit::WebResourceLoader*, void (WebKit::WebResourceLoader::*)(IPC::SharedBufferReference&&, unsigned long)) (connection=<optimized out>, function=<optimized out>, object=0x7f6fde6db360, decoder=...) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebKit/Platform/IPC/HandleMessage.h:213
#28 WebKit::WebResourceLoader::didReceiveWebResourceLoaderMessage(IPC::Connection&, IPC::Decoder&) (this=0x7f6fde6db360, connection=<optimized out>, decoder=...) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/_builddir/DerivedSources/WebKit/WebResourceLoaderMessageReceiver.cpp:76
#29 0x00007f88eb01d01a in IPC::Connection::dispatchMessage(std::unique_ptr<IPC::Decoder, std::default_delete<IPC::Decoder> >) (this=0x7f88ca0504e0, message=std::unique_ptr<IPC::Decoder> = {...}) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebKit/Platform/IPC/Connection.cpp:1242
#30 0x00007f88eb01eada in IPC::Connection::dispatchOneIncomingMessage() (this=0x7f88ca0504e0) at /usr/include/c++/12.1.0/bits/unique_ptr.h:189
#31 0x00007f88e9c91c55 in WTF::Function<void ()>::operator()() const (this=<synthetic pointer>) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WTF/wtf/Function.h:79
#32 WTF::RunLoop::performWork() (this=0x7f88ca0100e0) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WTF/wtf/RunLoop.cpp:147
#33 0x00007f88e9cf330d in operator() (userData=<optimized out>, __closure=0x0) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WTF/wtf/glib/RunLoopGLib.cpp:80
#34 _FUN(gpointer) () at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WTF/wtf/glib/RunLoopGLib.cpp:82
#35 0x00007f88e9cf3d8d in operator() (__closure=0x0, userData=0x7f88ca0100e0, callback=0x7f88e9cf3300 <_FUN(gpointer)>, source=0x55e1fb8e1cf0) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WTF/wtf/glib/RunLoopGLib.cpp:53
#36 _FUN(GSource*, GSourceFunc, gpointer) () at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WTF/wtf/glib/RunLoopGLib.cpp:56
#37 0x00007f88e69a39e1 in g_main_dispatch (context=<optimized out>) at ../glib/gmain.c:3444
#38 g_main_context_dispatch (context=<optimized out>) at ../glib/gmain.c:4162
#39 0x00007f88e69a3f38 in g_main_context_iterate (context=0x55e1fb8a2070, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../glib/gmain.c:4238
#40 0x00007f88e69a421f in g_main_loop_run (loop=0x55e1fb89ac50) at ../glib/gmain.c:4438
#41 0x00007f88e9cf3ef0 in WTF::RunLoop::run() () at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WTF/wtf/glib/RunLoopGLib.cpp:108
#42 0x00007f88eb48c7ff in WebKit::AuxiliaryProcessMainBase<WebKit::WebProcess, true>::run(int, char**) (argc=3, argv=0x7ffdb98aa548, this=0x7ffdb98aa3b0) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebKit/Shared/AuxiliaryProcessMain.h:71
#43 WebKit::AuxiliaryProcessMainBase<WebKit::WebProcess, true>::run(int, char**) (argv=0x7ffdb98aa548, argc=3, this=0x7ffdb98aa3b0) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebKit/Shared/AuxiliaryProcessMain.h:58
#44 WebKit::AuxiliaryProcessMain<WebKit::WebProcessMainGtk>(int, char**) (argc=3, argv=0x7ffdb98aa548) at /usr/lib/debug/source/sdk/webkitgtk-6.0.bst/Source/WebKit/Shared/AuxiliaryProcessMain.h:97
#45 0x00007f88ea22954a in __libc_start_call_main (main=main@entry=0x55e1fb307060 <main>, argc=argc@entry=3, argv=argv@entry=0x7ffdb98aa548) at ../sysdeps/nptl/libc_start_call_main.h:58
#46 0x00007f88ea22960b in __libc_start_main_impl (main=0x55e1fb307060 <main>, argc=3, argv=0x7ffdb98aa548, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=<optimized out>) at ../csu/libc-start.c:389
#47 0x000055e1fb307095 in _start ()

Actually, I tested three different leaked web processes, and discovered that two of them had hung here in ImageDecoderGStreamer. Either something is going wrong with the locking and condition variables inside WebCore::ImageDecoderGStreamer::pushEncodedData, and the call m_sampleCondition.wait(m_sampleLock) at ImageDecoderGStreamer.cpp:446 waits forever, OR perhaps we never receive GST_MESSAGE_EOS or GST_MESSAGE_ERROR, causing the loop to never terminate. Since I didn't catch this live, I'm not sure which.

Is there a clear repro scenario?

Can you share the `t a a bt` gdb output too?

(In reply to Philippe Normand from comment #4)
> Is there a clear repro scenario?

Nope, although I have some suspicions and will see if I can find one.

(In reply to Philippe Normand from comment #5)
> Can you share the `t a a bt` gdb output too?

I'll keep an eye out for this. Will collect one next time I catch it.

If possible a gst log would be nice too, GST_DEBUG="3,webkitimage*:6"

(In reply to Philippe Normand from comment #7)
> If possible a gst log would be nice too, GST_DEBUG="3,webkitimage*:6"

If I can find a reproducer, OK. Otherwise, there's no good way to get this.

Created attachment 464127 [details]
gdb.txt

I believe this deadlock is triggered by visiting articles on cnn.com. Still don't have a reliable reproducer unfortunately, so no GStreamer log, but I did catch three hung web processes today so I got the requested all-threads backtrace, attached.

I notice GStreamer is being used on a *lot* of  different threads here. ImageDecoderGStreamer specifically is in use on three different threads:

 * Thread 1 is calling ImageDecoderGStreamer::pushEncodedData and is blocked on line 463 m_innerDecoder = nullptr, which triggers the call to the callback inside InnerDecoder::preparePipeline, where it waits on line 394 for the condition variable: decoder.m_messageCondition.wait(decoder.m_messageLock).
 * Thread 26 is also waiting in the same callback on line 394, though with a different and much simpler backtrace.
 * Finally, thread 28 is waiting in ImageDecoderGStreamer::setHasEOS on line 294 for the condition variable m_handlerCondition.wait(m_handlerLock).

This is notably a little different from the first backtrace I attached above, where ImageDecoderGStreamer::pushEncodedData was blocked on line 446 instead of line 463. There must be a deadlock here somewhere, but unfortunately I do not see it. (I confused myself a bit at first because I forgot that the condition variable will release its lock.)

I guess the process leaks started after 247678@main, because now any process hang caused it to be leaked. Good thing is that now those hangs are noticeable, but leaking a process is by far worse. So, I think we should prevent the process leak even if that means we won't notice the hangs anymore (the one being debugged already would be great to fix though, I will move use a separate bug). The network process has a watchdog work queue to force a process exit after 10 seconds since the connection was closed. We could do the same for the web process.

> The network process has a watchdog work queue to force a process exit after 10 seconds since the connection was closed. We could do the same for the web process.

That sounds much simpler than what I would have suggested. Good idea. Didn't know about that. That said, can you create a separate bug report for robustness improvements? I'm very interested in this too, but let's focus this bug on ImageDecoderGStreamer.

(In reply to Michael Catanzaro from comment #11)
> That said, can you create a separate bug report for
> robustness improvements? I'm very interested in this too, but let's focus
> this bug on ImageDecoderGStreamer.

I just rediscovered bug #249272 from last week, as if I didn't report it myself. <_<

https://bugs.webkit.org/show_bug.cgi?id=249775 might help (or not).

FWIW, I'll likely attempt a rewrite of this decoder, basing it on the new element harness component that should hopefully land soon, it's part of the WebCodec patch for video encoding/decoding support.

Unfortunately bug #249775 did not fix this.

The web process now has a watchdog thread (added in bug #249272) that will crash (after bug #250377) 10 seconds after the UI process exits if the web process main thread did not exit. I hit the crash a few times shortly after updating to WebKitGTK 2.39.4 and took a backtrace of all threads to see what was going on. The web process main thread was waiting on the condition variable in ImageDecoderGStreamer::pushEncodedData at ImageDecoderGStreamer.cpp:457.

*** Bug 243639 has been marked as a duplicate of this bug. ***

*** Bug 251114 has been marked as a duplicate of this bug. ***

Is this still happening after updating to 2.39.7?

Dunno, just managed to upgrade Ephy Tech Preview about an hour ago. We'll find out....

So far so... good?

Relatively sure, yes. Closing.