Bug 167876 – [Soup] Deadlock in NetworkProcess

• Component: WebKitGTK
• Status: RESOLVED FIXED

[Tomas Popela]

Loading big messages in Evolution could leave NetworkProcess in deadlock, causing Evolution to not load anything later. It was introduced in http://trac.webkit.org/changeset/210374 (bisected there).

Thread 1 (Thread 0x7f0e6feb6fc0 (LWP 21043)):
#0  0x00007f0e678dc460 in pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f0e6a9645eb in WTF::ThreadCondition::timedWait(WTF::Mutex&, double) () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libjavascriptcoregtk-4.0.so.18
#2  0x00007f0e6a93d963 in WTF::ParkingLot::parkConditionallyImpl(void const*, WTF::ScopedLambda<bool ()> const&, WTF::ScopedLambda<void ()> const&, WTF::TimeWithDynamicClockType const&) () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libjavascriptcoregtk-4.0.so.18
#3  0x00007f0e6a934234 in WTF::LockAlgorithm<unsigned char, (unsigned char)1, (unsigned char)2>::lockSlow(WTF::Atomic<unsigned char>&) () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libjavascriptcoregtk-4.0.so.18
#4  0x00007f0e6dd7dc3c in webkitSoupRequestInputStreamReadAsync(_GInputStream*, void*, unsigned long, int, _GCancellable*, void (*)(_GObject*, _GAsyncResult*, void*), void*) () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libwebkit2gtk-4.0.so.37
#5  0x00007f0e64c432d9 in g_input_stream_read_async (stream=0x10387e0 [WebKitSoupRequestInputStream], buffer=0x7f0e13df0000, count=8192, io_priority=0, cancellable=0x10d8cf0 [GCancellable], callback=
    0x7f0e6dc502c0 <WebKit::NetworkDataTaskSoup::readCallback(_GInputStream*, _GAsyncResult*, WebKit::NetworkDataTaskSoup*)>, user_data=0x7f0e13df8480) at ginputstream.c:633
#6  0x00007f0e6dc4ef6f in WebKit::NetworkDataTaskSoup::read() () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libwebkit2gtk-4.0.so.37
#7  0x00007f0e6dc4f58d in WebKit::NetworkDataTaskSoup::didRead(long) () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libwebkit2gtk-4.0.so.37
#8  0x00007f0e6dc50428 in WebKit::NetworkDataTaskSoup::readCallback(_GInputStream*, _GAsyncResult*, WebKit::NetworkDataTaskSoup*) () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libwebkit2gtk-4.0.so.37
#9  0x00007f0e64c43f9a in async_ready_callback_wrapper (source_object=0x10387e0 [WebKitSoupRequestInputStream], res=0x119ae30, user_data=0x7f0e13df8480) at ginputstream.c:532
#10 0x00007f0e64c6b9d4 in g_task_return_now (task=0x119ae30 [GTask]) at gtask.c:1121
#11 0x00007f0e64c6c086 in g_task_return (task=0x119ae30 [GTask], type=<optimized out>) at gtask.c:1179
#12 0x00007f0e6dd7daf3 in webkitSoupRequestInputStreamReadAsyncResultComplete(_GTask*, void*, unsigned long) () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libwebkit2gtk-4.0.so.37
#13 0x00007f0e6dd7df6e in webkitSoupRequestInputStreamAddData () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libwebkit2gtk-4.0.so.37
#14 0x00007f0e6dda28c5 in WebKit::CustomProtocolManager::didReceiveMessage(IPC::Connection&, IPC::Decoder&) () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libwebkit2gtk-4.0.so.37
#15 0x00007f0e6da2e749 in IPC::MessageReceiverMap::dispatchMessage(IPC::Connection&, IPC::Decoder&) () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libwebkit2gtk-4.0.so.37
#16 0x00007f0e6dc060c6 in WebKit::NetworkProcess::didReceiveMessage(IPC::Connection&, IPC::Decoder&) () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libwebkit2gtk-4.0.so.37
#17 0x00007f0e6da2a50b in IPC::Connection::dispatchMessage(std::unique_ptr<IPC::Decoder, std::default_delete<IPC::Decoder> >) () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libwebkit2gtk-4.0.so.37
#18 0x00007f0e6da2b078 in IPC::Connection::dispatchOneMessage() () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libwebkit2gtk-4.0.so.37
#19 0x00007f0e6a93fb25 in WTF::RunLoop::performWork() () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libjavascriptcoregtk-4.0.so.18
#20 0x00007f0e6a965b79 in WTF::RunLoop::RunLoop()::{lambda(void*)#1}::_FUN(void*) () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libjavascriptcoregtk-4.0.so.18
#21 0x00007f0e644c3e42 in g_main_dispatch (context=0x98eb30) at gmain.c:3203
#22 0x00007f0e644c3e42 in g_main_context_dispatch (context=context@entry=0x98eb30) at gmain.c:3856
#23 0x00007f0e644c41c0 in g_main_context_iterate (context=0x98eb30, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at gmain.c:3929
#24 0x00007f0e644c44e2 in g_main_loop_run (loop=0x98ed20) at gmain.c:4125
#25 0x00007f0e6a966410 in WTF::RunLoop::run() () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libjavascriptcoregtk-4.0.so.18
#26 0x00007f0e6dc59706 in int WebKit::ChildProcessMain<WebKit::NetworkProcess, WebKit::ChildProcessMainBase>(int, char**) () at /home/tpopela/dev/upstream/WebKit/WebKitBuild/Release/lib/libwebkit2gtk-4.0.so.37
#27 0x00007f0e60d2a401 in __libc_start_main (main=0x400ac0 <main>, argc=2, argv=0x7ffc78222528, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffc78222518) at ../csu/libc-start.c:289
#28 0x0000000000400b1a in _start ()

[Carlos Garcia Campos]

WebKitSoupRequestInputStream uses a read lock.What is happening is that webkitSoupRequestInputStreamAddData takes the lock, and it calls webkitSoupRequestInputStreamPendingReadAsyncComplete with the lock help. That causes webkitSoupRequestInputStreamReadAsync to be called again to read the next chunk, but in the same run loop operation. webkitSoupRequestInputStreamReadAsync also takes the read lock. I don't know why we are using that read lock, I don't think it's needed, at least now everything should happen in the main thread. But I'm going to look at it in more detail. If the lock is needed, then the solution is to release it before calling webkitSoupRequestInputStreamPendingReadAsyncComplete

[Carlos Garcia Campos]

According to myself in https://bugs.webkit.org/show_bug.cgi?id=85880#c9 the mutex is needed, because glib will use a thread to implement read_async, and webkitSoupRequestInputStreamAddData can be called from other thread. Before r210374, that thread was the message work queue, that's why this never happened. Now it's the main thread, so I guess we just need to release the lock.

[Carlos Garcia Campos]

(In reply to comment #2)
> According to myself in https://bugs.webkit.org/show_bug.cgi?id=85880#c9 the
> mutex is needed, because glib will use a thread to implement read_async, and
> webkitSoupRequestInputStreamAddData can be called from other thread. Before
> r210374, that thread was the message work queue, that's why this never
> happened. Now it's the main thread, so I guess we just need to release the
> lock.

But I was wrong, because we are overriding GInputStreamClass::read_async, claiming we know how to handle the async request, and therefore not using the fallback implementation in GInputStream that runs the thread. It makes sense, indeed, because we are actually a GMemoryInputStream, there's no io in the read function, so we can handle it in the main thread.

[Carlos Garcia Campos]

Created attachment 300716 [details]
Patch

[Carlos Garcia Campos]

Committed r211734: <http://trac.webkit.org/changeset/211734>