Bug 112300 – Opening the Web Inspector takes 5s (undocked)

• Status: RESOLVED
• Resolution: FIXED
• Component: WebKit2

[Timothy Hatcher]

In Safari 6, it only takes 2s. Ideally, it would take less than 200ms.

* STEPS TO REPRODUCE
1. Go to about:blank
2. Opt-Cmd-C to open the Web Inspector to the JS console.
--> Takes 5s

The first two seconds are spent waiting on sync IPC:

Samples	# Self		Symbol Name
64   22.9%	0	 	                        WebKit::WebInspector::createInspectorPage()
64   22.9%	0	 	                         bool CoreIPC::Connection::sendSync<Messages::WebInspectorProxy::CreateInspectorPage>(Messages::WebInspectorProxy::CreateInspectorPage const&, Messages::WebInspectorProxy::CreateInspectorPage::Reply const&, unsigned long long, double, unsigned int)
64   22.9%	0	 	                          CoreIPC::Connection::sendSyncMessage(unsigned long long, WTF::PassOwnPtr<CoreIPC::MessageEncoder>, double, unsigned int)
64   22.9%	0	 	                           CoreIPC::Connection::waitForSyncReply(unsigned long long, double, unsigned int)
64   22.9%	0	 	                            CoreIPC::BinarySemaphore::wait(double)
64   22.9%	0	 	                             WTF::ThreadCondition::timedWait(WTF::Mutex&, double)
64   22.9%	0	 	                              _pthread_cond_wait
64   22.9%	64	 	                               __psynch_cvwait

There seems to be a CoreIPC deadlock, caused by this in the UI process at the same time as the above backtrace:

Samples	# Self		Symbol Name
62   28.8%	0	 	                           WebKit::WebInspectorProxy::createInspectorWindow()
62   28.8%	0	 	                            -[NSWindow setFrameAutosaveName:]
62   28.8%	0	 	                             -[NSWindow _setFrameAutosaveName:changeFrame:]
62   28.8%	0	 	                              -[NSWindow setFrameUsingName:]
62   28.8%	0	 	                               -[NSWindow _setFrameUsingName:domain:force:]
62   28.8%	0	 	                                -[NSWindow _setFrameFromString:overrideTopLeft:constrainFullFrame:force:]
62   28.8%	0	 	                                 -[NSWindow _setFrameCommon:display:stashSize:]
61   28.3%	0	 	                                  -[NSThemeFrame handleSetFrameCommonRedisplay]
61   28.3%	0	 	                                   -[NSView displayIfNeeded]
60   27.9%	0	 	                                    -[NSView _displayRectIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:]
60   27.9%	0	 	                                     -[NSThemeFrame _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:]
60   27.9%	0	 	                                      -[NSView _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:]
60   27.9%	0	 	                                       -[NSView _recursiveDisplayAllDirtyWithLockFocus:visRect:]
58   26.9%	0	 	                                        -[NSView _recursiveDisplayAllDirtyWithLockFocus:visRect:]
58   26.9%	0	 	                                         -[NSView _recursiveDisplayAllDirtyWithLockFocus:visRect:]
58   26.9%	0	 	                                          -[NSView _drawRect:clip:]
58   26.9%	0	 	                                           -[NSView(NSLayerKitGlue) _drawRectAsLayerTree:]
58   26.9%	0	 	                                            CA::Transaction::commit()
58   26.9%	0	 	                                             CA::Context::commit_transaction(CA::Transaction*)
58   26.9%	0	 	                                              CA::Layer::layout_and_display_if_needed(CA::Transaction*)
58   26.9%	0	 	                                               CA::Layer::display_if_needed(CA::Transaction*)
58   26.9%	0	 	                                                CA::Layer::display()
58   26.9%	0	 	                                                 -[NSView(NSLayerKitGlue) _displayLayer:]
58   26.9%	0	 	                                                  +[NSView _performWithoutAnimation:]
58   26.9%	0	 	                                                   WebKit::TiledCoreAnimationDrawingAreaProxy::waitForPossibleGeometryUpdate()
58   26.9%	0	 	                                                    bool CoreIPC::Connection::waitForAndDispatchImmediately<Messages::DrawingAreaProxy::DidUpdateGeometry>(unsigned long long, double)
58   26.9%	0	 	                                                     CoreIPC::Connection::waitForMessage(CoreIPC::StringReference, CoreIPC::StringReference, unsigned long long, double)
58   26.9%	0	 	                                                      WTF::ThreadCondition::timedWait(WTF::Mutex&, double)
58   26.9%	0	 	                                                       _pthread_cond_wait
58   26.9%	58	 	                                                        __psynch_cvwait

<rdar://problem/13412219>

[Timothy Hatcher]

Created attachment 193026 [details]
Proposed Change

[WebKit Review Bot]

Attachment 193026 [details] did not pass style-queue:

Failed to run "['Tools/Scripts/check-webkit-style', '--diff-files', u'Source/WebKit2/ChangeLog', u'Source/WebKit2/Shared/WebPreferencesStore.cpp', u'Source/WebKit2/Shared/WebPreferencesStore.h', u'Source/WebKit2/UIProcess/WebInspectorProxy.cpp', u'Source/WebKit2/UIProcess/WebInspectorProxy.h', u'Source/WebKit2/UIProcess/mac/WebInspectorProxyMac.mm']" exit_code: 1
Source/WebKit2/ChangeLog:6:  Need whitespace between colon and description  [changelog/filechangedescriptionwhitespace] [5]
Source/WebKit2/ChangeLog:8:  Need whitespace between colon and description  [changelog/filechangedescriptionwhitespace] [5]
Source/WebKit2/ChangeLog:9:  Need whitespace between colon and description  [changelog/filechangedescriptionwhitespace] [5]
Total errors found: 3 in 6 files


If any of these errors are false positives, please file a bug against check-webkit-style.

[Alexey Proskuryakov]

What is the reason for CreateInspectorPage to not be handled? Normally, sync messages are delivered even when waiting for a sync message response, to prevent deadlocks.

[Timothy Hatcher]

I'm not sure. Either way this patch is a much better approach. We were just marking the WKView as hidden before anyway. So not trying to make the window until later is cleaner and safer.

[Alexey Proskuryakov]

CC'ing Sam and Anders, who may know the answer.

[Timothy Hatcher]

Created attachment 193304 [details]
Proposed Additional Change

[Geoffrey Garen]

Comment on attachment 193304 [details]
Proposed Additional Change

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

r=me

> Source/WebKit/mac/ChangeLog:26
> [phone]  Timothy Hatcher  <[e-mail]>
> +
> +        Need a short description (OOPS!).
> +        Need the bug URL (OOPS!).
> +
> +        Reviewed by NOBODY (OOPS!).
> +
> +        * WebCoreSupport/WebInspectorClient.mm:
> +        (-[WebInspectorWindowController init]):

Oops!

[Geoffrey Garen]

Comment on attachment 193026 [details]
Proposed Change

r=me

[Alexey Proskuryakov]

As discussed on IRC, the root cause for the delay is that -[WKView updateLayers] makes UI process wait 0.5 seconds for a DidUpdateGeometry message, and this of course causes a temporary deadlock if WebProcess waits for some sync message response, and cannot send this message.

[Timothy Hatcher]

r145961 and r145963