Bug 167876 - [Soup] Deadlock in NetworkProcess
Summary: [Soup] Deadlock in NetworkProcess
Status: RESOLVED FIXED
Alias: None
Product: WebKit
Classification: Unclassified
Component: WebKitGTK (show other bugs)
Version: WebKit Nightly Build
Hardware: Unspecified Unspecified
: P2 Normal
Assignee: Nobody
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-02-06 05:45 PST by Tomas Popela
Modified: 2017-02-06 10:02 PST (History)
2 users (show)

See Also:


Attachments
Patch (3.27 KB, patch)
2017-02-06 06:29 PST, Carlos Garcia Campos
mcatanzaro: review+
Details | Formatted Diff | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Tomas Popela 2017-02-06 05:45:23 PST
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 ()
Comment 1 Carlos Garcia Campos 2017-02-06 05:57:38 PST
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
Comment 2 Carlos Garcia Campos 2017-02-06 06:06:01 PST
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.
Comment 3 Carlos Garcia Campos 2017-02-06 06:19:53 PST
(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.
Comment 4 Carlos Garcia Campos 2017-02-06 06:29:49 PST
Created attachment 300716 [details]
Patch
Comment 5 Carlos Garcia Campos 2017-02-06 10:02:32 PST
Committed r211734: <http://trac.webkit.org/changeset/211734>