Bug 191812 – Regression(r238330) ProcessSwap.WebInspector API test is a flaky crash in debug

• Status: RESOLVED
• Resolution: FIXED
• Component: Web Inspector

[Chris Dumez]

ProcessSwap.WebInspector API test is a flaky crash in debug:

TestWebKitAPI.ProcessSwap.WebInspector
        _RegisterApplication(), FAILED TO establish the default connection to the WindowServer, _CGSDefaultConnection() is NULL.
        Received data during response processing, queuing it.
        _RegisterApplication(), FAILED TO establish the default connection to the WindowServer, _CGSDefaultConnection() is NULL.
        _RegisterApplication(), FAILED TO establish the default connection to the WindowServer, _CGSDefaultConnection() is NULL.
        Received data during response processing, queuing it.
        ASSERTION FAILED: !m_frontendConnection
        /Volumes/Data/slave/mojave-debug/build/Source/WebKit/WebProcess/WebPage/WebInspector.cpp(80) : void WebKit::WebInspector::setFrontendConnection(IPC::Attachment)
        1   0x646e526f9 WTFCrash
        2   0x630002a2b WTFCrashWithInfo(int, char const*, char const*, int)
        3   0x631030c2a WebKit::WebInspector::setFrontendConnection(IPC::Attachment)
        4   0x6310f1d48 void IPC::callMemberFunctionImpl<WebKit::WebInspector, void (WebKit::WebInspector::*)(IPC::Attachment), std::__1::tuple<IPC::Attachment>, 0ul>(WebKit::WebInspector*, void (WebKit::WebInspector::*)(IPC::Attachment), std::__1::tuple<IPC::Attachment>&&, std::__1::integer_sequence<unsigned long, 0ul>)
        5   0x6310f1c70 void IPC::callMemberFunction<WebKit::WebInspector, void (WebKit::WebInspector::*)(IPC::Attachment), std::__1::tuple<IPC::Attachment>, std::__1::integer_sequence<unsigned long, 0ul> >(std::__1::tuple<IPC::Attachment>&&, WebKit::WebInspector*, void (WebKit::WebInspector::*)(IPC::Attachment))
        6   0x6310f16a4 void IPC::handleMessage<Messages::WebInspector::SetFrontendConnection, WebKit::WebInspector, void (WebKit::WebInspector::*)(IPC::Attachment)>(IPC::Decoder&, WebKit::WebInspector*, void (WebKit::WebInspector::*)(IPC::Attachment))
        7   0x6310f092c WebKit::WebInspector::didReceiveMessage(IPC::Connection&, IPC::Decoder&)
        8   0x63111ad32 WebKit::WebPage::didReceiveMessage(IPC::Connection&, IPC::Decoder&)
        9   0x6300b1e9a IPC::MessageReceiverMap::dispatchMessage(IPC::Connection&, IPC::Decoder&)
        10  0x630db5b1d WebKit::WebProcess::didReceiveMessage(IPC::Connection&, IPC::Decoder&)
        11  0x630049f2c IPC::Connection::dispatchMessage(IPC::Decoder&)
        12  0x63003c311 IPC::Connection::dispatchMessage(std::__1::unique_ptr<IPC::Decoder, std::__1::default_delete<IPC::Decoder> >)
        13  0x63004acf7 IPC::Connection::dispatchOneIncomingMessage()
        14  0x63006b828 IPC::Connection::enqueueIncomingMessage(std::__1::unique_ptr<IPC::Decoder, std::__1::default_delete<IPC::Decoder> >)::$_14::operator()()
        15  0x63006b739 WTF::Function<void ()>::CallableWrapper<IPC::Connection::enqueueIncomingMessage(std::__1::unique_ptr<IPC::Decoder, std::__1::default_delete<IPC::Decoder> >)::$_14>::call()
        16  0x646e79ffd WTF::Function<void ()>::operator()() const
        17  0x646ed2e5d WTF::RunLoop::performWork()
        18  0x646ed3704 WTF::RunLoop::performWork(void*)
        19  0x7fff4189cf09 __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__
        20  0x7fff4189ceaf __CFRunLoopDoSource0
        21  0x7fff41880d5c __CFRunLoopDoSources0
        22  0x7fff41880303 __CFRunLoopRun
        23  0x7fff4187fbe6 CFRunLoopRunSpecific
        24  0x7fff43c043ba -[NSRunLoop(NSRunLoop) runMode:beforeDate:]
        25  0x7fff43c0428f -[NSRunLoop(NSRunLoop) run]
        26  0x7fff6ed31ee6 _xpc_objc_main
        27  0x7fff6ed319e5 _xpc_copy_xpcservice_dictionary
        28  0x1073c2055 WebKit::XPCServiceMain(int, char const**)
        29  0x1073c2342 main
        30  0x7fff6eafb08d start
        _RegisterApplication(), FAILED TO establish the default connection to the WindowServer, _CGSDefaultConnection() is NULL.
        Received data during response processing, queuing it.
        Received data during response processing, queuing it.
        LEAK: 2 WebProcessPool
        
        /Volumes/Data/slave/mojave-debug/build/Tools/TestWebKitAPI/Tests/WebKitCocoa/ProcessSwapOnNavigation.mm:2075
        Expected: (pid2) != (pid3), actual: 29417 vs 29417
        
        
        /Volumes/Data/slave/mojave-debug/build/Tools/TestWebKitAPI/Tests/WebKitCocoa/ProcessSwapOnNavigation.mm:2076
        Expected equality of these values:
          numberOfDecidePolicyCalls
            Which is: 4
          3

[Chris Dumez]

https://build.webkit.org/builders/Apple%20Mojave%20Debug%20WK1%20%28Tests%29/builds/739/steps/run-api-tests/logs/stdio

[Chris Dumez]

I was unable to reproduce locally.

[Ryosuke Niwa]

I can reproduce it locally on iMac Pro:

$ ./Tools/Scripts/run-api-tests --debug ProcessSwap.WebInspector
Running tests       
    _RegisterApplication(), FAILED TO establish the default connection to the WindowServer, _CGSDefaultConnection() is NULL.
    Received data during response processing, queuing it.
    _RegisterApplication(), FAILED TO establish the default connection to the WindowServer, _CGSDefaultConnection() is NULL.
    _RegisterApplication(), FAILED TO establish the default connection to the WindowServer, _CGSDefaultConnection() is NULL.
    ASSERTION FAILED: !m_frontendConnection
    /Volumes/Data/webkit2/Source/WebKit/WebProcess/WebPage/WebInspector.cpp(80) : void WebKit::WebInspector::setFrontendConnection(IPC::Attachment)
    1   0x11f66f419 WTFCrash
    2   0x10af0d19b WTFCrashWithInfo(int, char const*, char const*, int)
    3   0x10bf349ea WebKit::WebInspector::setFrontendConnection(IPC::Attachment)
    4   0x10bff5d78 void IPC::callMemberFunctionImpl<WebKit::WebInspector, void (WebKit::WebInspector::*)(IPC::Attachment), std::__1::tuple<IPC::Attachment>, 0ul>(WebKit::WebInspector*, void (WebKit::WebInspector::*)(IPC::Attachment), std::__1::tuple<IPC::Attachment>&&, std::__1::integer_sequence<unsigned long, 0ul>)
    5   0x10bff5ca0 void IPC::callMemberFunction<WebKit::WebInspector, void (WebKit::WebInspector::*)(IPC::Attachment), std::__1::tuple<IPC::Attachment>, std::__1::integer_sequence<unsigned long, 0ul> >(std::__1::tuple<IPC::Attachment>&&, WebKit::WebInspector*, void (WebKit::WebInspector::*)(IPC::Attachment))
    6   0x10bff56d4 void IPC::handleMessage<Messages::WebInspector::SetFrontendConnection, WebKit::WebInspector, void (WebKit::WebInspector::*)(IPC::Attachment)>(IPC::Decoder&, WebKit::WebInspector*, void (WebKit::WebInspector::*)(IPC::Attachment))
    7   0x10bff495c WebKit::WebInspector::didReceiveMessage(IPC::Connection&, IPC::Decoder&)
    8   0x10c01efe2 WebKit::WebPage::didReceiveMessage(IPC::Connection&, IPC::Decoder&)
    9   0x10afbc5da IPC::MessageReceiverMap::dispatchMessage(IPC::Connection&, IPC::Decoder&)
    10  0x10bcbc45d WebKit::WebProcess::didReceiveMessage(IPC::Connection&, IPC::Decoder&)
    11  0x10af5466c IPC::Connection::dispatchMessage(IPC::Decoder&)
    12  0x10af46a51 IPC::Connection::dispatchMessage(std::__1::unique_ptr<IPC::Decoder, std::__1::default_delete<IPC::Decoder> >)
    13  0x10af55437 IPC::Connection::dispatchOneIncomingMessage()
    14  0x10af75f68 IPC::Connection::enqueueIncomingMessage(std::__1::unique_ptr<IPC::Decoder, std::__1::default_delete<IPC::Decoder> >)::$_14::operator()()
    15  0x10af75e79 WTF::Function<void ()>::CallableWrapper<IPC::Connection::enqueueIncomingMessage(std::__1::unique_ptr<IPC::Decoder, std::__1::default_delete<IPC::Decoder> >)::$_14>::call()
    16  0x11f696c5d WTF::Function<void ()>::operator()() const
    17  0x11f6ef90d WTF::RunLoop::performWork()
    18  0x11f6f01b4 WTF::RunLoop::performWork(void*)
...
    Received data during response processing, queuing it.
    Received data during response processing, queuing it.
    LEAK: 2 WebProcessPool
    
    /Volumes/Data/webkit2/Tools/TestWebKitAPI/Tests/WebKitCocoa/ProcessSwapOnNavigation.mm:2076
    Expected: (pid2) != (pid3), actual: 36821 vs 36821
    
    
    /Volumes/Data/webkit2/Tools/TestWebKitAPI/Tests/WebKitCocoa/ProcessSwapOnNavigation.mm:2077
    Expected equality of these values:
      numberOfDecidePolicyCalls
        Which is: 4
      3

[Joseph Pecoraro]

(In reply to Ryosuke Niwa from comment #3)
> I can reproduce it locally on iMac Pro:
> 
> $ ./Tools/Scripts/run-api-tests --debug ProcessSwap.WebInspector

This also reproduces the issue for me. I'm taking a look.

[Chris Dumez]

(In reply to Joseph Pecoraro from comment #4)
> (In reply to Ryosuke Niwa from comment #3)
> > I can reproduce it locally on iMac Pro:
> > 
> > $ ./Tools/Scripts/run-api-tests --debug ProcessSwap.WebInspector
> 
> This also reproduces the issue for me. I'm taking a look.

FYI, https://bugs.webkit.org/show_bug.cgi?id=191814 is probably more urgent.

[Joseph Pecoraro]

My understanding of what is going on so far is:

    • WebProcess (A) asks UIProcess for inspector
      • UIProcess launches InspectorProcess
        • InspectorProcess launches, sends new connection attachment (1) to UIProcess (on way to WebProcess)

    * UIProcess navigates
      * Swaps WebProcess (A) swaps to (B)
        * Asks InspectorProcess for a new connection
          * InspectorProcess, sends new connection attachment (2) to UIProcess (on way to WebProcess)

    • UIProcess receives (1) sends to current WebProcess (B)
    • UIProcess receives (2) sends to current WebProcess (B)

So this looks like its just message ordering due to very quickly performing actions in the UIProcess before receiving messages from the InspectorProcess. In this case it would be harmless for WebProcess (B) to use the latest IPC attachment, and in fact we will always want to use the most current IPC::Attachment.

I just want to verify a few things, like that we aren't getting messages in suspended processes.

Maybe it's possible for the UIProcess avoid sending multiple messages to a WebProcess but just using the latest is the simplest path forward.

[Joseph Pecoraro]

Created attachment 355255 [details]
[PATCH] Proposed Fix

[WebKit Commit Bot]

Comment on attachment 355255 [details]
[PATCH] Proposed Fix

Clearing flags on attachment: 355255

Committed r238369: <https://trac.webkit.org/changeset/238369>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.

[Radar WebKit Bug Importer]

<rdar://problem/46162470>