Bug 197266 – UI process crash when using callOnMainThread() after the main thread dispatcher has been destroyed

• Status: RESOLVED
• Resolution: FIXED
• Component: WebKitGTK

[Michael Catanzaro]

Created attachment 368205 [details]
Full backtrace

I've been hitting this non-reproducible crash somewhat regularly when closing MiniBrowser for a few months now, but never figured out what's going wrong and never bothered to report it until now. The backtrace is really hard to read due to inlining, and I just don't see what's happening.

The crash occurs here in Connection::invalidate:

    m_connectionQueue->dispatch([protectedThis = makeRef(*this)]() mutable {
        protectedThis->platformInvalidate();
    });

But it's hard to see what's going on. The lambda executes, then lambda is destroyed, and so protectedThis (the Ref<Connection>) is destroyed... presumably the refcount drops to 0 for some reason (no clue why -- doesn't look like Connection::platformInvalidate is doing anything that could cause this -- but anyway it's clearly expected as that's why there's the protector), then ~Connection destructor is called... and something goes wrong, it's really not clear what from the backtrace. I had been thinking the crash occurs when destroying m_incomingMessagesThrottler, which is a std::unique_ptr<MessagesThrottler>. The MessagesThrottler class contains a RunLoop::Timer<Connection>, and RunLoopGLib.cpp is the only place in WebKit where we directly call g_source_set_ready_time(), so that looked suspicious. But there's no way the ~Timer or ~TimerBase destructors should be calling g_source_set_ready_time(). They only call g_source_destroy(). Doesn't make sense to me.

Anyway:

Truncated backtrace:
Thread no. 1 (10 frames)
 #0 g_source_set_ready_time at ../glib/gmain.c:1857
 #1 WTF::ThreadSafeRefCounted<IPC::Connection, (WTF::DestructionThread)1>::deref at /usr/include/c++/9/bits/unique_ptr.h:283
 #3 WTF::Ref<IPC::Connection, WTF::DumbPtrTraits<IPC::Connection> >::~Ref at DerivedSources/ForwardingHeaders/wtf/Ref.h:60
 #4 IPC::Connection::<lambda()>::~<lambda> at ../Source/WebKit/Platform/IPC/Connection.cpp:385
 #5 WTF::Function<void()>::CallableWrapper<IPC::Connection::invalidate()::<lambda()> >::~CallableWrapper at DerivedSources/ForwardingHeaders/wtf/Function.h:92
 #6 WTF::Function<void()>::CallableWrapper<IPC::Connection::invalidate()::<lambda()> >::~CallableWrapper(void) at DerivedSources/ForwardingHeaders/wtf/Function.h:92
 #7 std::default_delete<WTF::Function<void ()>::CallableWrapperBase>::operator()(WTF::Function<void ()>::CallableWrapperBase*) const at /usr/include/c++/9/bits/unique_ptr.h:75
 #8 std::unique_ptr<WTF::Function<void ()>::CallableWrapperBase, std::default_delete<WTF::Function<void ()>::CallableWrapperBase> >::~unique_ptr() at /usr/include/c++/9/bits/unique_ptr.h:289
 #9 WTF::Function<void ()>::~Function() at ../Source/WTF/wtf/Function.h:36
 #10 WTF::WorkQueue::<lambda()>::~<lambda> at ../Source/WTF/wtf/generic/WorkQueueGeneric.cpp:62

[Michael Catanzaro]

I forgot to mention: the crash occurs on a secondary thread while the main thread is running exit handlers. That probably isn't helping. Maybe we need to make sure all RunLoops get stopped *before* exit handlers.

[Libor Bukata]

I was able to reproduce this issue on Solaris with yelp command:
$ yelp help:gnome-help/getting-started

I created a small library that enables to print a backtrace,
time, and some data. Webkit was instrumented to observe timers
lifetime. The results reveal the both why program crashed and
how was g_source_set_ready_time() called.

thread 1 at time 1568271108695699336 (2019-09-12 06:51:48)
timer pointer: 0x65abd1700
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::RunLoop::TimerBase::~TimerBase()+0x36 [0x7fbd36df416a]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::RunLoop::Timer<WTF::MainThreadDispatcher>::~Timer()+0x2a [0x7fbd36df10f8]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::MainThreadDispatcher::~MainThreadDispatcher()+0x18 [0x7fbd36df105c]
/lib/amd64/libc.so.1'_exithandle+0x7d [0x7fbd4f15269d]
/lib/amd64/libc.so.1'exit+0x11 [0x7fbd4f1334d1]
/usr/bin/yelp'_start+0x4e [0x409e0e]

... other thread 13 ms later...

thread 14 at time 1568271108709000361 (2019-09-12 06:51:48)
data pointer: 0x65abd1700
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::RunLoop::TimerBase::updateReadyTime()+0x24 [0x7fbd36df4288]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::RunLoop::TimerBase::start(WTF::Seconds, bool)+0x53 [0x7fbd36df43b7]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::RunLoop::TimerBase::startInternal(WTF::Seconds, bool)+0x60 [0x7fbd36b75b74]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::RunLoop::TimerBase::startOneShot(WTF::Seconds)+0x2f [0x7fbd36b75b11]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::MainThreadDispatcher::schedule()+0x23 [0x7fbd36df1027]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::scheduleDispatchFunctionsOnMainThread()+0x6a [0x7fbd36df0f93]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::callOnMainThread(WTF::Function<void ()>&&)+0xa7 [0x7fbd36d7095f]
/usr/lib/amd64/libwebkit2gtk-4.0.so.37.37.6'WTF::ThreadSafeRefCounted<IPC::Connection, (WTF::DestructionThread)1>::deref() const+0x70 [0x7fbd45a08fd8]
/usr/lib/amd64/libwebkit2gtk-4.0.so.37.37.6'WTF::Ref<IPC::Connection, WTF::DumbPtrTraits<IPC::Connection> >::~Ref()+0x2c [0x7fbd45a04eba]
/usr/lib/amd64/libwebkit2gtk-4.0.so.37.37.6'IPC::Connection::invalidate()::{lambda()#2}::~invalidate()+0x18 [0x7fbd45d00d38]
/usr/lib/amd64/libwebkit2gtk-4.0.so.37.37.6'WTF::Function<void ()>::CallableWrapper<IPC::Connection::invalidate()::{lambda()#2}>::~CallableWrapper()+0x2a [0x7fbd45d07238]
/usr/lib/amd64/libwebkit2gtk-4.0.so.37.37.6'WTF::Function<void ()>::CallableWrapper<IPC::Connection::invalidate()::{lambda()#2}>::~CallableWrapper()+0x18 [0x7fbd45d07260]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'std::default_delete<WTF::Function<void ()>::CallableWrapperBase>::operator()(WTF::Function<void ()>::CallableWrapperBase*) const+0x2e [0x7fbd36595bde]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'std::unique_ptr<WTF::Function<void ()>::CallableWrapperBase, std::default_delete<WTF::Function<void ()>::CallableWrapperBase> >::~unique_ptr()+0x49 [0x7fbd36593b17]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::Function<void ()>::~Function()+0x18 [0x7fbd365923cc]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::WorkQueue::dispatch(WTF::Function<void ()>&&)::{lambda()#1}::~Function()+0x1c [0x7fbd36df136a]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::Function<void ()>::CallableWrapper<WTF::WorkQueue::dispatch(WTF::Function<void ()>&&)::{lambda()#1}>::~CallableWrapper()+0x2a [0x7fbd36df2030]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::Function<void ()>::CallableWrapper<WTF::WorkQueue::dispatch(WTF::Function<void ()>&&)::{lambda()#1}>::~CallableWrapper()+0x18 [0x7fbd36df2058]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'std::default_delete<WTF::Function<void ()>::CallableWrapperBase>::operator()(WTF::Function<void ()>::CallableWrapperBase*) const+0x2e [0x7fbd36595bde]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'std::unique_ptr<WTF::Function<void ()>::CallableWrapperBase, std::default_delete<WTF::Function<void ()>::CallableWrapperBase> >::~unique_ptr()+0x49 [0x7fbd36593b17]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::Function<void ()>::~Function()+0x18 [0x7fbd365923cc]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::RunLoop::performWork()+0x19f [0x7fbd36d85e97]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::RunLoop::RunLoop()::{lambda(void*)#1}::operator()(void*) const+0x1c [0x7fbd36df372e]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::RunLoop::RunLoop()::{lambda(void*)#1}::_FUN(void*)+0x1d [0x7fbd36df3752]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::{lambda(_GSource*, int (*)(void*), void*)#1}::operator()(_GSource*, int (*)(void*), void*) const+0x56 [0x7fbd36df36ce]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::{lambda(_GSource*, int (*)(void*), void*)#1}::_FUN(_GSource*, int (*)(void*), void*)+0x2d [0x7fbd36df36fd]
/usr/lib/amd64/libglib-2.0.so.0.5200.0'g_main_context_dispatch+0x138 [0x7fbd4eaeb7e8]
/usr/lib/amd64/libglib-2.0.so.0.5200.0'0xebb78 [0x7fbd4eaebb78]
/usr/lib/amd64/libglib-2.0.so.0.5200.0'g_main_loop_run+0xd2 [0x7fbd4eaebeb2]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::RunLoop::run()+0xac [0x7fbd36df3c0c]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::WorkQueue::platformInitialize(char const*, WTF::WorkQueue::Type, WTF::WorkQueue::QOS)::{lambda()#1}::operator()() const+0x32 [0x7fbd36df11d0]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::Function<void ()>::CallableWrapper<WTF::WorkQueue::platformInitialize(char const*, WTF::WorkQueue::Type, WTF::WorkQueue::QOS)::{lambda()#1}>::call()+0x1c [0x7fbd36df306e]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::Function<void ()>::operator()() const+0x5e [0x7fbd36c11506]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::Thread::entryPoint(WTF::Thread::NewThreadContext*)+0x191 [0x7fbd36d88997]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::wtfThreadEntryPoint(void*)+0x18 [0x7fbd36df638a]
/lib/amd64/libc.so.1'_thrp_setup+0xa4 [0x7fbd4f248c94]
/lib/amd64/libc.so.1'_lwp_start+0x0 [0x7fbd4f248f70]

So, it is clear that there was an attempt to update timer
after it was destructed. I continued to search a detached
thread or never destroyed process that tried to update it.

/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::WorkQueue::WorkQueue(char const*, WTF::WorkQueue::Type, WTF::WorkQueue::QOS)+0x40 [0x7fdf013b5b40]
/usr/lib/amd64/libjavascriptcoregtk-4.0.so.18.13.7'WTF::WorkQueue::create(char const*, WTF::WorkQueue::Type, WTF::WorkQueue::QOS)+0x39 [0x7fdf013b5ae5]
/usr/lib/amd64/libwebkit2gtk-4.0.so.37.37.6'IPC::Connection::Connection(int, bool, IPC::Connection::Client&)+0xb8 [0x7fdf149001ee]
/usr/lib/amd64/libwebkit2gtk-4.0.so.37.37.6'IPC::Connection::createClientConnection(int, IPC::Connection::Client&)+0x3a [0x7fdf1490007e]
/usr/lib/amd64/libwebkit2gtk-4.0.so.37.37.6'WebKit::AuxiliaryProcess::initialize(WebKit::AuxiliaryProcessInitializationParameters const&)+0x101 [0x7fdf1494a287]
/usr/lib/amd64/libwebkit2gtk-4.0.so.37.37.6'WebKit::NetworkProcess::NetworkProcess(WebKit::AuxiliaryProcessInitializationParameters&&)+0x35a [0x7fdf147938a8]
/usr/lib/amd64/libwebkit2gtk-4.0.so.37.37.6'WTF::NeverDestroyed<WebKit::NetworkProcess>::NeverDestroyed<WebKit::AuxiliaryProcessInitializationParameters>(WebKit::AuxiliaryProcessInitializationParameters&&)+0x49 [0x7fdf148f87f3]
/usr/lib/amd64/libwebkit2gtk-4.0.so.37.37.6'void WebKit::initializeAuxiliaryProcess<WebKit::NetworkProcess>(WebKit::AuxiliaryProcessInitializationParameters&&)+0x4c [0x7fdf148ec5ac]
/usr/lib/amd64/libwebkit2gtk-4.0.so.37.37.6'int WebKit::AuxiliaryProcessMain<WebKit::NetworkProcess, WebKit::NetworkProcessMain>(int, char**)+0x72 [0x7fdf148f89df]
/usr/lib/amd64/libwebkit2gtk-4.0.so.37.37.6'NetworkProcessMainUnix+0x20 [0x7fdf148ec5f6]
/usr/lib/amd64/WebKitNetworkProcess'main+0x3d [0x40133d]
/usr/lib/amd64/WebKitNetworkProcess'_start+0x43 [0x401163]

So, it seems that there is a "never-destroyed" WebKit process that
accesses the timer after it was destructed. I do not know why the usage
of WTF::NeverDestroyed is necessary but the problem can be solved by
never calling the destructor of MainThreadDispatcher class, please see
the attached patch. After applying the patch, it does not crash anymore.

However, there will be a memory leak since the destructor of m_timer member
of MainThreadDispatcher class is never called...

[Libor Bukata]

Created attachment 379106 [details]
Fixes a crash when the program exists.

Note that it resolves the crash during
the program termination but it leaks
memory because the timer destructor was
never called.

[Carlos Garcia Campos]

Ok, so it was ThreadSafeRefCounted calling callOnMainThread() after the main thread dispatcher has been destroyed. It's perfectly fine to use NeverDestroyed for the main thread dispatcher, there's no leak because want it alive until the process exists (and all memory is freed). We need a proper patch, though, including a ChangeLog entry. See https://webkit.org/contributing-code/ Thanks!

[Libor Bukata]

Created attachment 379126 [details]
Fixes a crash when the program exists (Updated changelog, WebKit format).

The patch was created by using svn-create-patch
utility and the ChangeLog was updated.

[Michael Catanzaro]

I think I agree this is the proper fix, nice!

[Michael Catanzaro]

Comment on attachment 379126 [details]
Fixes a crash when the program exists (Updated changelog, WebKit format).

View in context: https://bugs.webkit.org/attachment.cgi?id=379126&action=review

> Source/WTF/ChangeLog:3
> +        Fix a possible crash during the program termination.

Please just make sure the first line of the ChangeLog matches the title of the bug. I've just renamed the bug, so:

UI process crash when using callOnMainThread() after the main thread dispatcher has been destroyed

Other than that, LGTM.

Set the r: Bugzilla flag to r? to request review. Leave r+ for the reviewer.

[Libor Bukata]

Created attachment 379127 [details]
Fixes a crash when the program exists (updated description).

Used bug title as a description in ChangeLog file.

[Libor Bukata]

Comment on attachment 379126 [details]
Fixes a crash when the program exists (Updated changelog, WebKit format).

View in context: https://bugs.webkit.org/attachment.cgi?id=379126&action=review

>> Source/WTF/ChangeLog:3
>> +        Fix a possible crash during the program termination.
> 
> Please just make sure the first line of the ChangeLog matches the title of the bug. I've just renamed the bug, so:
> 
> UI process crash when using callOnMainThread() after the main thread dispatcher has been destroyed
> 
> Other than that, LGTM.
> 
> Set the r: Bugzilla flag to r? to request review. Leave r+ for the reviewer.

Thank you for your comments. I updated the description in the patch.

[WebKit Commit Bot]

Comment on attachment 379127 [details]
Fixes a crash when the program exists (updated description).

Clearing flags on attachment: 379127

Committed r250126: <https://trac.webkit.org/changeset/250126>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.