Bug 217684

Summary: REGRESSION (r268384): ASSERTION FAILED: _startCount > 1 in -[WKMouseDeviceObserver stop]
Product: WebKit Reporter: Ryan Haddad <ryanhaddad>
Component: New BugsAssignee: Devin Rousso <hi>
Status: RESOLVED FIXED    
Severity: Normal CC: hi, thorton, webkit-bot-watchers-bugzilla, webkit-bug-importer, wenson_hsieh
Priority: P2 Keywords: InRadar
Version: WebKit Nightly Build   
Hardware: Unspecified   
OS: Unspecified   
See Also: https://bugs.webkit.org/show_bug.cgi?id=212580
Attachments:
Description Flags
Patch
thorton: review-
Patch
none
Patch ews-feeder: commit-queue-

Description Ryan Haddad 2020-10-13 17:03:37 PDT
Seeing the following assertion failure with 8 API tests on iOS Debug bots after https://trac.webkit.org/changeset/268384/webkit

        ASSERTION FAILED: _startCount > 1
        /Volumes/Data/slave/ios-simulator-14-debug/build/Source/WebKit/UIProcess/ios/WKMouseDeviceObserver.mm(61) : -[WKMouseDeviceObserver stop]
        1   0x104327f09 WTFCrash
        2   0x10e73db2b WTFCrashWithInfo(int, char const*, char const*, int)
        3   0x10f7ded25 -[WKMouseDeviceObserver stop]
        4   0x10f80ac33 WebKit::WebProcessProxy::platformDestroy()
        5   0x10f615fe6 WebKit::WebProcessProxy::~WebProcessProxy()
        6   0x10f616665 WebKit::WebProcessProxy::~WebProcessProxy()
        7   0x10f6166ec WebKit::WebProcessProxy::~WebProcessProxy()
        8   0x10f2b4ed4 WTF::ThreadSafeRefCounted<WebKit::WebProcessProxy, (WTF::DestructionThread)0>::deref() const::'lambda'()::operator()() const
        9   0x10f2b4e6d WTF::ThreadSafeRefCounted<WebKit::WebProcessProxy, (WTF::DestructionThread)0>::deref() const
        10  0x10f2b4e1e WebKit::WebProcessProxy::deref()
        11  0x10f2b4def WTF::Ref<WebKit::WebProcessProxy, WTF::DumbPtrTraits<WebKit::WebProcessProxy> >::~Ref()
        12  0x10f281845 WTF::Ref<WebKit::WebProcessProxy, WTF::DumbPtrTraits<WebKit::WebProcessProxy> >::~Ref()
        13  0x10f62ad98 WebKit::WebPageProxy::close()::$_6::~$_6()
        14  0x10f5bc205 WebKit::WebPageProxy::close()::$_6::~$_6()
        15  0x10f65cfe5 WTF::Detail::CallableWrapper<WebKit::WebPageProxy::close()::$_6, void>::~CallableWrapper()
        16  0x10f65ce45 WTF::Detail::CallableWrapper<WebKit::WebPageProxy::close()::$_6, void>::~CallableWrapper()
        17  0x10f65ce6c WTF::Detail::CallableWrapper<WebKit::WebPageProxy::close()::$_6, void>::~CallableWrapper()
        18  0x10433d63f std::__1::default_delete<WTF::Detail::CallableWrapperBase<void> >::operator()(WTF::Detail::CallableWrapperBase<void>*) const
        19  0x10433d5bf std::__1::unique_ptr<WTF::Detail::CallableWrapperBase<void>, std::__1::default_delete<WTF::Detail::CallableWrapperBase<void> > >::reset(WTF::Detail::CallableWrapperBase<void>*)
        20  0x10433d559 std::__1::unique_ptr<WTF::Detail::CallableWrapperBase<void>, std::__1::default_delete<WTF::Detail::CallableWrapperBase<void> > >::~unique_ptr()
        21  0x10433d535 std::__1::unique_ptr<WTF::Detail::CallableWrapperBase<void>, std::__1::default_delete<WTF::Detail::CallableWrapperBase<void> > >::~unique_ptr()
        22  0x10433d515 WTF::Function<void ()>::~Function()
        23  0x10433c485 WTF::Function<void ()>::~Function()
        24  0x1043d0f0e WTF::RunLoop::performWork()
        25  0x1043d5641 WTF::RunLoop::performWork(void*)
        26  0x136f63845 __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__
        27  0x136f6373d __CFRunLoopDoSource0
        28  0x136f62c1f __CFRunLoopDoSources0
        29  0x136f5d3f7 __CFRunLoopRun
        30  0x136f5cb9e CFRunLoopRunSpecific
        31  0x1369b0e61 -[NSRunLoop(NSRunLoop) runMode:beforeDate:]
        Child process terminated with signal 11: Segmentation fault
        SHOULD NEVER BE REACHED
        /Volumes/Data/slave/ios-simulator-14-debug/build/Source/WebKit/Shared/Authentication/cocoa/AuthenticationManagerCocoa.mm(45) : virtual void WebKit::AuthenticationManager::initializeConnection(IPC::Connection *)


https://build.webkit.org/builders/Apple-iOS-14-Simulator-Debug-WK2-Tests/builds/244/steps/run-api-tests/logs/stdio
Comment 1 Radar WebKit Bug Importer 2020-10-13 17:04:07 PDT
<rdar://problem/70272646>
Comment 2 Devin Rousso 2020-10-13 17:27:52 PDT
Created attachment 411283 [details]
Patch

I'm not sure why/how this is happening, but the `ASSERT` isn't really necessary
Comment 3 Tim Horton 2020-10-13 17:53:30 PDT
Comment on attachment 411283 [details]
Patch

You need to understand how you got here; a double-stop could mean you go to zero while having outstanding clients, so r- until you figure out how.
Comment 4 Devin Rousso 2020-10-13 18:23:17 PDT
(In reply to Tim Horton from comment #3)
> Comment on attachment 411283 [details]
> Patch
> 
> You need to understand how you got here; a double-stop could mean you go to zero while having outstanding clients, so r- until you figure out how.

here's what I know so far:

The log above indicates that these tests are failing:
 - WKWebView.EvaluateJavaScriptBlockCrash
 - WebProcessCache.ClearWhenEnteringCache
 - WKProcessPool.WarmInitialProcess
 - WKProcessPool.PrewarmedProcessCrash
 - WKWebView.LocalStorageClear
 - ProcessSwap.ClosePageAfterCrossSiteProvisionalLoad
 - WKNavigation.ProcessCrashDuringCallback
 - _WKDownload.CrashAfterDownloadDidFinishWhenDownloadProxyHoldsTheLastRefOnWebProcessPool

None of these tests crash on my machine using an iOS simulator.

There is only one place that `[WKMouseDeviceObserver stop]` is called, and that's inside `WebProcessProxy::platformDestroy` (private member function), which is called inside `WebProcessProxy::~WebProcessProxy`.

`[WKMouseDeviceObserver start]` is called inside `WebProcessProxy::platformCreate` (private member function), which is called inside `WebProcessProxy::WebProcessProxy`, and inside `Tools/TestWebKitAPI/Tests/WebKitCocoa/iOSMouseSupport.mm` (all of which ran before any test crashed).

I know that `WebProcessProxy::WebProcessProxy` and `WebProcessProxy::~WebProcessProxy` are not somehow being called more than once because there are other `ASSERT` in both that should trigger in that case.

Even more confusingly, `WKStylusDeviceObserver` has the exact same logic in the exact same places as `WKMouseDeviceObserver` and yet its `ASSERT` is not being triggered.

clearly there is something magical happening here :(

I will try to reproduce this tonight by running the entire API test suite, but I wonder if it wouldn't be more prudent to just change `WKMouseDeviceObserver`/`WKStylusDeviceObserver` to add the listener as soon as the `sharedInstance` is created and remove `stop` (I only added it to try to be more efficient when there are no `WebProcessProxy`, but I think that that's likely very rare) instead of trying to chase down the cause of what should be impossible.  I'll see what I find tonight.
Comment 5 Devin Rousso 2020-10-13 19:48:43 PDT
Created attachment 411294 [details]
Patch

(In reply to Devin Rousso from comment #4)
> clearly there is something magical happening here :(

I have found the magic!  It was past me being stupid 😬

It should be `_startCount >= 1` as it's totally possible for there to have been only one prior call to `-[WKMouseDeviceObserver start]`/`-[WKStylusDeviceObserver start]`.

I tested this change locally and it passed all the API tests with no crashes.

I think I'd still suggest the patch as I've written it as it's more permissive/forgiving (e.g. if someone _really_ wants to make sure the listener has stopped then they can call it without having to worry about a crash).  If there is a preference/precedence for ensuring that things like this listener are not over-stopped then I can just adjust the `ASSERT`.
Comment 6 Tim Horton 2020-10-13 23:48:13 PDT
(In reply to Devin Rousso from comment #5)
> Created attachment 411294 [details]
> Patch
> 
> (In reply to Devin Rousso from comment #4)
> > clearly there is something magical happening here :(
> 
> I have found the magic!  It was past me being stupid 😬
> 
> It should be `_startCount >= 1` as it's totally possible for there to have
> been only one prior call to `-[WKMouseDeviceObserver
> start]`/`-[WKStylusDeviceObserver start]`.
> 
> I tested this change locally and it passed all the API tests with no crashes.
> 
> I think I'd still suggest the patch as I've written it as it's more
> permissive/forgiving (e.g. if someone _really_ wants to make sure the
> listener has stopped then they can call it without having to worry about a
> crash).

This is very strange reasoning for exactly the reason I said the first time around (your "someone" who "really wants to make sure the listener has stopped" is screwing over someone /else/ who is using your global API). Counted APIs need to be /very strict/.

>  If there is a preference/precedence for ensuring that things like
> this listener are not over-stopped then I can just adjust the `ASSERT`.

Plz put the assert back.
Comment 7 Devin Rousso 2020-10-14 11:03:54 PDT
Created attachment 411351 [details]
Patch
Comment 8 EWS 2020-10-14 13:27:47 PDT
Committed r268482: <https://trac.webkit.org/changeset/268482>

All reviewed patches have been landed. Closing bug and clearing flags on attachment 411351 [details].