Bug 170395 – [Debug] ASSERT(!throwScope.exception()) on imported/w3c/web-platform-tests/fetch/api/cors/cors-preflight-status-worker.html

• Status: RESOLVED
• Resolution: FIXED
• Component: JavaScriptCore

[Alexey Proskuryakov]

imported/w3c/web-platform-tests/fetch/api/cors/cors-preflight-status.html very frequently asserts:

https://webkit-test-results.webkit.org/dashboards/flakiness_dashboard.html#showAllRuns=true&tests=imported%2Fw3c%2Fweb-platform-tests%2Ffetch%2Fapi%2Fcors%2Fcors-preflight-status.html

Thread 24 Crashed:: WebCore: Worker
0   com.apple.JavaScriptCore      	0x0000000111327457 WTFCrash + 39 (Assertions.cpp:323)
1   com.apple.JavaScriptCore      	0x00000001109d968d JSC::Interpreter::executeCall(JSC::ExecState*, JSC::JSObject*, JSC::CallType, JSC::CallData const&, JSC::JSValue, JSC::ArgList const&) + 205 (Interpreter.cpp:897)
2   com.apple.JavaScriptCore      	0x000000011013879e JSC::call(JSC::ExecState*, JSC::JSValue, JSC::CallType, JSC::CallData const&, JSC::JSValue, JSC::ArgList const&) + 190 (CallData.cpp:39)
3   com.apple.WebCore             	0x00000001199ecc9f WebCore::DeferredPromise::callFunction(JSC::ExecState&, JSC::JSValue, JSC::JSValue) + 287 (JSDOMPromise.cpp:59)
4   com.apple.WebCore             	0x0000000119440d15 WebCore::DeferredPromise::reject(JSC::ExecState&, JSC::JSValue) + 85 (JSDOMPromise.h:127)
5   com.apple.WebCore             	0x00000001199ed16f WebCore::DeferredPromise::reject(int, WTF::String const&) + 287 (JSDOMPromise.cpp:109)
6   com.apple.WebCore             	0x0000000119031cd7 void WebCore::DOMPromiseBase::reject<WebCore::$_0>(WebCore::$_0&&) + 71 (JSDOMPromise.h:167)
7   com.apple.WebCore             	0x0000000119031b38 WebCore::FetchResponse::BodyLoader::didFail() + 264 (FetchResponse.cpp:141)
8   com.apple.WebCore             	0x000000011902d269 WebCore::FetchLoader::didFail(WebCore::ResourceError const&) + 41 (FetchLoader.cpp:152)

[Radar WebKit Bug Importer]

<rdar://problem/31394017>

[Alexey Proskuryakov]

First occurrence on 2017-03-09.

[Alexey Proskuryakov]

Marked as flaky assert in r214727.

[youenn fablet]

I doubt this is imported/w3c/web-platform-tests/fetch/api/cors/cors-preflight-status.html since there is no worker here.
Might be LayoutTests/imported/w3c/web-platform-tests/fetch/api/cors/cors-preflight-status-worker.html if it is run just before cors-preflight-status.html

[youenn fablet]

From https://build.webkit.org/builders/Apple%20Sierra%20Debug%20WK1%20(Tests)/builds/334/steps/layout-test/logs/stdio

18:20:23.064 25505 worker/2 imported/w3c/web-platform-tests/fetch/api/cors/cors-preflight-status-worker.html output stderr lines:
18:20:23.064 25505   ASSERTION FAILED: !throwScope.exception()
18:20:23.064 25505   /Volumes/Data/slave/sierra-debug/build/Source/JavaScriptCore/interpreter/Interpreter.cpp(897) : JSC::JSValue JSC::Interpreter::executeCall(CallFrame *, JSC::JSObject *, JSC::CallType, const JSC::CallData &, JSC::JSValue, const JSC::ArgList &)
18:20:23.064 25505   1   0x1061bc8bd WTFCrash
18:20:23.064 25505   2   0x105ab271b JSC::Interpreter::executeCall(JSC::ExecState*, JSC::JSObject*, JSC::CallType, JSC::CallData const&, JSC::JSValue, JSC::ArgList const&)
18:20:23.064 25505   3   0x10528d5b8 JSC::call(JSC::ExecState*, JSC::JSValue, JSC::CallType, JSC::CallData const&, JSC::JSValue, JSC::ArgList const&)
18:20:23.064 25505   4   0x10528d86a JSC::profiledCall(JSC::ExecState*, JSC::ProfilingReason, JSC::JSValue, JSC::CallType, JSC::CallData const&, JSC::JSValue, JSC::ArgList const&)
18:20:23.064 25505   5   0x105be9ea8 JSC::JSJobMicrotask::run(JSC::ExecState*)
18:20:23.064 25505   6   0x10ef0d834 WebCore::JSGlobalObjectCallback::call()
18:20:23.064 25505   7   0x10ef0d671 WebCore::JSGlobalObjectTask::JSGlobalObjectTask(WebCore::JSDOMGlobalObject*, WTF::Ref<JSC::Microtask>&&)::$_0::operator()(WebCore::ScriptExecutionContext&) const
18:20:23.065 25505   8   0x10ef0d514 WTF::Function<void (WebCore::ScriptExecutionContext&)>::CallableWrapper<WebCore::JSGlobalObjectTask::JSGlobalObjectTask(WebCore::JSDOMGlobalObject*, WTF::Ref<JSC::Microtask>&&)::$_0>::call(WebCore::ScriptExecutionContext&)
18:20:23.065 25505 worker/2 imported/w3c/web-platform-tests/fetch/api/cors/cors-preflight-status-worker.html passed

[youenn fablet]

executeCall is hitting a throwScope.exception() in executeCall.
In DeferredPromise::reject, we create a DOM exception which might generate such thing.
It might be that the creation of the exception is not happening correctly when we are closing abruptly the Worker.

[Mark Lam]

(In reply to youenn fablet from comment #6)
> executeCall is hitting a throwScope.exception() in executeCall.
> In DeferredPromise::reject, we create a DOM exception which might generate
> such thing.
> It might be that the creation of the exception is not happening correctly
> when we are closing abruptly the Worker.

Shouldn't DeferredPromise::reject() catch all exceptions?

[youenn fablet]

(In reply to Mark Lam from comment #7)
> (In reply to youenn fablet from comment #6)
> > executeCall is hitting a throwScope.exception() in executeCall.
> > In DeferredPromise::reject, we create a DOM exception which might generate
> > such thing.
> > It might be that the creation of the exception is not happening correctly
> > when we are closing abruptly the Worker.
> 
> Shouldn't DeferredPromise::reject() catch all exceptions?

We could make DeferredPromise::reject() exit early (and not call executeCall) when creation of the JSValue is not going right and is making throwScope.exception() to be true.
I would think that this is only happening in the context of Workers though.
We added several tweaks specific to Workers (see createDeferredPromise for instance).

In Window environment, we should then just ASSERT() while in Worker environment we should return early.

[youenn fablet]

Created attachment 306182 [details]
Adding early assertions

[youenn fablet]

Created attachment 306186 [details]
Adding early assertions - fixing release builds

[Mark Lam]

Comment on attachment 306186 [details]
Adding early assertions - fixing release builds

r=me

[WebKit Commit Bot]

Comment on attachment 306186 [details]
Adding early assertions - fixing release builds

Clearing flags on attachment: 306186

Committed r214897: <http://trac.webkit.org/changeset/214897>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.

[Geoffrey Garen]

Comment on attachment 306186 [details]
Adding early assertions - fixing release builds

How does this patch solve the original problem, that there was a pending JS exception when we called into the JS reject handler?

I don't see any code in this patch to handle or clear the exception -- only code to assert that there was no exception.

Put another way, the purpose of a catch scope is provide access to a clearException() function. But this patch never calls clearException(). So why does it declare a catch scope?

[Mark Lam]

(In reply to Geoffrey Garen from comment #14)
> Comment on attachment 306186 [details]
> Adding early assertions - fixing release builds
> 
> How does this patch solve the original problem, that there was a pending JS
> exception when we called into the JS reject handler?
> 
> I don't see any code in this patch to handle or clear the exception -- only
> code to assert that there was no exception.
> 
> Put another way, the purpose of a catch scope is provide access to a
> clearException() function. But this patch never calls clearException(). So
> why does it declare a catch scope?

Since this failure is intermittent, Youenn intended to use this patch to test whether the failure came from createDOMException().  Further action depends on what we see from the bots as a result of that.

[Geoffrey Garen]

Got it. Thanks!

[youenn fablet]

Let's see what happens

[youenn fablet]

From https://build.webkit.org/results/Apple%20El%20Capitan%20Debug%20WK1%20(Tests)/r214947%20(361)/DumpRenderTree-2305-crash-log.txt
Thread 32 Crashed:: WebCore: Worker
0   com.apple.JavaScriptCore      	0x000000010253b867 WTFCrash + 39 (Assertions.cpp:323)
1   com.apple.WebCore             	0x000000010aba11b8 WebCore::DeferredPromise::reject(int, WTF::String const&) + 424 (JSDOMPromise.cpp:117)
2   com.apple.WebCore             	0x000000010a1e6167 void WebCore::DOMPromiseBase::reject<WebCore::$_0>(WebCore::$_0&&) + 71 (JSDOMPromise.h:167)
3   com.apple.WebCore             	0x000000010a1e5fc8 WebCore::FetchResponse::BodyLoader::didFail() + 264 (FetchResponse.cpp:141)
4   com.apple.WebCore             	0x000000010a1e16f9 WebCore::FetchLoader::didFail(WebCore::ResourceError const&) + 41 (FetchLoader.cpp:152)
5   com.apple.WebCore             	0x000000010c6b1e52 WebCore::ThreadableLoaderClientWrapper::didFail(WebCore::ResourceError const&) + 66 (ThreadableLoaderClientWrapper.h:88)

We are hitting the new assertion.
Same applies to https://build.webkit.org/results/Apple%20iOS%2010%20Simulator%20Debug%20WK2%20(Tests)/r214957%20(404)/com.apple.WebKit.WebContent.Development-16889-crash-log.txt

Assumption is probably correct

[youenn fablet]

An older crash from this same test is different, probably also proving that we have issues elsewhere and that the way we stop workers are probably not working well with promises.

Thread 25 Crashed:: WebCore: Worker
0   com.apple.JavaScriptCore      	0x0000000103df2077 WTFCrash + 39 (Assertions.cpp:323)
1   com.apple.JavaScriptCore      	0x00000001036cb63d JSC::Interpreter::executeCall(JSC::ExecState*, JSC::JSObject*, JSC::CallType, JSC::CallData const&, JSC::JSValue, JSC::ArgList const&) + 205 (Interpreter.cpp:897)
2   com.apple.JavaScriptCore      	0x0000000102e8c23e JSC::call(JSC::ExecState*, JSC::JSValue, JSC::CallType, JSC::CallData const&, JSC::JSValue, JSC::ArgList const&) + 190 (CallData.cpp:39)
3   com.apple.JavaScriptCore      	0x0000000102e8c47a JSC::profiledCall(JSC::ExecState*, JSC::ProfilingReason, JSC::JSValue, JSC::CallType, JSC::CallData const&, JSC::JSValue, JSC::ArgList const&) + 106 (CallData.cpp:59)
4   com.apple.JavaScriptCore      	0x0000000103808e26 JSC::JSJobMicrotask::run(JSC::ExecState*) + 518 (JSJob.cpp:75)
5   com.apple.WebCore             	0x000000010c416222 WebCore::JSGlobalObjectCallback::call() + 418 (JSDOMGlobalObjectTask.cpp:69)
6   com.apple.WebCore             	0x000000010c415421 WebCore::JSGlobalObjectTask::JSGlobalObjectTask(WebCore::JSDOMGlobalObject*, WTF::Ref<JSC::Microtask>&&)::$_0::operator()(WebCore::ScriptExecutionContext&) const + 33 (JSDOMGlobalObjectTask.cpp:90)
7   com.apple.WebCore             	0x000000010c415377 WTF::Function<void (WebCore::ScriptExecutionContext&)>::CallableWrapper<WebCore::JSGlobalObjectTask::JSGlobalObjectTask(WebCore::JSDOMGlobalObject*, WTF::Ref<JSC::Microtask>&&)::$_0>::call(WebCore::ScriptExecutionContext&) + 55 (Function.h:89)

[youenn fablet]

Created attachment 306443 [details]
Patch

[youenn fablet]

(In reply to youenn fablet from comment #20)
> Created attachment 306443 [details]
> Patch

This patch only fixes the low-level issue.
Ideally, we should not need to do that since the early return based on isSuspended() should be the sufficient.
Might be good to add a FIXME maybe.

[Mark Lam]

Comment on attachment 306443 [details]
Patch

r=me

[WebKit Commit Bot]

Comment on attachment 306443 [details]
Patch

Clearing flags on attachment: 306443

Committed r215083: <http://trac.webkit.org/changeset/215083>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.