Bug 209560 - [ Mac wk1] ASSERTION FAILED: m_wrapper under WebCore::XMLHttpRequestUpload::dispatchProgressEvent
Summary: [ Mac wk1] ASSERTION FAILED: m_wrapper under WebCore::XMLHttpRequestUpload::d...
Status: RESOLVED FIXED
Alias: None
Product: WebKit
Classification: Unclassified
Component: Tools / Tests (show other bugs)
Version: WebKit Nightly Build
Hardware: Macintosh macOS 10.15
: P2 Normal
Assignee: Chris Dumez
URL:
Keywords: InRadar
Depends on:
Blocks:
 
Reported: 2020-03-25 13:43 PDT by Jason Lawrence
Modified: 2020-03-26 14:33 PDT (History)
9 users (show)

See Also:


Attachments
Patch (7.93 KB, patch)
2020-03-26 12:12 PDT, Chris Dumez
no flags Details | Formatted Diff | Diff
Patch (4.57 KB, patch)
2020-03-26 13:24 PDT, Chris Dumez
no flags Details | Formatted Diff | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Jason Lawrence 2020-03-25 13:43:29 PDT
imported/w3c/web-platform-tests/xhr/send-response-upload-event-progress.htm 

Description:
This test is flaky failing and crashing on Mac wk1. The first failure is apparent on 03/12/2020.

History:
https://results.webkit.org/?suite=layout-tests&test=imported%2Fw3c%2Fweb-platform-tests%2Fxhr%2Fsend-response-upload-event-progress.htm&flavor=wk1&limit=50000

Diff:
--- /Volumes/Data/slave/catalina-release-tests-wk1/build/layout-test-results/imported/w3c/web-platform-tests/xhr/send-response-upload-event-progress-expected.txt
+++ /Volumes/Data/slave/catalina-release-tests-wk1/build/layout-test-results/imported/w3c/web-platform-tests/xhr/send-response-upload-event-progress-actual.txt
@@ -1,3 +1,5 @@
 
-PASS XMLHttpRequest: The send() method: Fire a progress event named progress on the XMLHttpRequestUpload (synchronous flag is unset) 
+Harness Error (TIMEOUT), message = null
 
+TIMEOUT XMLHttpRequest: The send() method: Fire a progress event named progress on the XMLHttpRequestUpload (synchronous flag is unset) Test timed out
+


Stderr:
stderr:
ASSERTION FAILED: m_wrapper
./bindings/js/JSEventListener.h(123) : JSC::JSObject *WebCore::JSEventListener::jsFunction(WebCore::ScriptExecutionContext &) const
1   0x10e1ec779 WTFCrash
2   0x124aafefb WTFCrashWithInfo(int, char const*, char const*, int)
3   0x126de73c8 WebCore::JSEventListener::jsFunction(WebCore::ScriptExecutionContext&) const
4   0x126de66eb WebCore::JSEventListener::handleEvent(WebCore::ScriptExecutionContext&, WebCore::Event&)
5   0x1274a1cac WebCore::EventTarget::innerInvokeEventListeners(WebCore::Event&, WTF::Vector<WTF::RefPtr<WebCore::RegisteredEventListener, WTF::DumbPtrTraits<WebCore::RegisteredEventListener> >, 1ul, WTF::CrashOnOverflow, 16ul, WTF::FastMalloc>, WebCore::EventTarget::EventInvokePhase)
6   0x12749dee2 WebCore::EventTarget::fireEventListeners(WebCore::Event&, WebCore::EventTarget::EventInvokePhase)
7   0x1274a186d WebCore::EventTarget::dispatchEvent(WebCore::Event&)
8   0x12944d468 WebCore::XMLHttpRequestUpload::dispatchProgressEvent(WTF::AtomString const&, unsigned long long, unsigned long long)
9   0x12944ee9f WebCore::XMLHttpRequest::didSendData(unsigned long long, unsigned long long)
10  0x127edfc76 WebCore::DocumentThreadableLoader::dataSent(WebCore::CachedResource&, unsigned long long, unsigned long long)
11  0x12804e3e3 WebCore::CachedRawResource::didSendData(unsigned long long, unsigned long long)
12  0x127fd00d1 WebCore::SubresourceLoader::didSendData(unsigned long long, unsigned long long)
13  0x127fb1568 WebCore::ResourceLoader::didSendData(WebCore::ResourceHandle*, unsigned long long, unsigned long long)
14  0x12953bd65 -[WebCoreResourceHandleAsOperationQueueDelegate connection:didSendBodyData:totalBytesWritten:totalBytesExpectedToWrite:]::$_6::operator()()
15  0x12953bc39 WTF::Detail::CallableWrapper<-[WebCoreResourceHandleAsOperationQueueDelegate connection:didSendBodyData:totalBytesWritten:totalBytesExpectedToWrite:]::$_6, void>::call()
16  0x10e216a4a WTF::Function<void ()>::operator()() const
17  0x10e25597b WTF::dispatchFunctionsFromMainThread()
18  0x10e258f31 WTF::timerFired(__CFRunLoopTimer*, void*)
19  0x7fff3b60f804 __CFRUNLOOP_IS_CALLING_OUT_TO_A_TIMER_CALLBACK_FUNCTION__
20  0x7fff3b60f3be __CFRunLoopDoTimer
21  0x7fff3b60ee9e __CFRunLoopDoTimers
22  0x7fff3b5f3aed __CFRunLoopRun
23  0x7fff3b5f2bd3 CFRunLoopRunSpecific
24  0x10cad769d runTest(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&)
25  0x10cad68aa runTestingServerLoop()
26  0x10cad5fe3 dumpRenderTree(int, char const**)
27  0x10cad809d DumpRenderTreeMain(int, char const**)
28  0x10cb66b12 main
29  0x7fff72c987fd start
Comment 1 Radar WebKit Bug Importer 2020-03-25 13:43:58 PDT
<rdar://problem/60887773>
Comment 2 Jason Lawrence 2020-03-25 13:49:54 PDT
I have marked this test as failing and crashing while this issue is investigated.
https://trac.webkit.org/changeset/259007/webkit
Comment 3 Jason Lawrence 2020-03-25 13:53:37 PDT
I was able to reproduce the failure with the command below.
run-webkit-tests --iterations 2000 --exit-after-n-failures 1 --exit-after-n-crashes-or-timeouts 1 --debug-rwt-logging --no-retry --force --no-build -f -1 imported/w3c/web-platform-tests/xhr/send-response-upload-event-progress.htm'
Comment 4 Chris Dumez 2020-03-26 10:45:20 PDT
(In reply to Jason Lawrence from comment #3)
> I was able to reproduce the failure with the command below.
> run-webkit-tests --iterations 2000 --exit-after-n-failures 1
> --exit-after-n-crashes-or-timeouts 1 --debug-rwt-logging --no-retry --force
> --no-build -f -1
> imported/w3c/web-platform-tests/xhr/send-response-upload-event-progress.htm'

This seems to reproduce a flaky timeout for me but not a crash.
Comment 5 Chris Dumez 2020-03-26 10:48:31 PDT
(In reply to Chris Dumez from comment #4)
> (In reply to Jason Lawrence from comment #3)
> > I was able to reproduce the failure with the command below.
> > run-webkit-tests --iterations 2000 --exit-after-n-failures 1
> > --exit-after-n-crashes-or-timeouts 1 --debug-rwt-logging --no-retry --force
> > --no-build -f -1
> > imported/w3c/web-platform-tests/xhr/send-response-upload-event-progress.htm'
> 
> This seems to reproduce a flaky timeout for me but not a crash.

Crash might have been fixed by http://trac.webkit.org/r259009 or http://trac.webkit.org/r258959.
Comment 6 Chris Dumez 2020-03-26 11:26:25 PDT
(In reply to Chris Dumez from comment #5)
> (In reply to Chris Dumez from comment #4)
> > (In reply to Jason Lawrence from comment #3)
> > > I was able to reproduce the failure with the command below.
> > > run-webkit-tests --iterations 2000 --exit-after-n-failures 1
> > > --exit-after-n-crashes-or-timeouts 1 --debug-rwt-logging --no-retry --force
> > > --no-build -f -1
> > > imported/w3c/web-platform-tests/xhr/send-response-upload-event-progress.htm'
> > 
> > This seems to reproduce a flaky timeout for me but not a crash.
> 
> Crash might have been fixed by http://trac.webkit.org/r259009 or
> http://trac.webkit.org/r258959.

Not fixed, I can now reproduce the crash with aggressive GC on:
run-webkit-tests --iterations 200 --no-retry --force --no-build -f -1 imported/w3c/web-platform-tests/xhr/send-response-upload-event-progress.htm --additional-env-var=JSC_slowPathAllocsBetweenGCs=10
Comment 7 Chris Dumez 2020-03-26 11:29:44 PDT
(In reply to Chris Dumez from comment #6)
> (In reply to Chris Dumez from comment #5)
> > (In reply to Chris Dumez from comment #4)
> > > (In reply to Jason Lawrence from comment #3)
> > > > I was able to reproduce the failure with the command below.
> > > > run-webkit-tests --iterations 2000 --exit-after-n-failures 1
> > > > --exit-after-n-crashes-or-timeouts 1 --debug-rwt-logging --no-retry --force
> > > > --no-build -f -1
> > > > imported/w3c/web-platform-tests/xhr/send-response-upload-event-progress.htm'
> > > 
> > > This seems to reproduce a flaky timeout for me but not a crash.
> > 
> > Crash might have been fixed by http://trac.webkit.org/r259009 or
> > http://trac.webkit.org/r258959.
> 
> Not fixed, I can now reproduce the crash with aggressive GC on:
> run-webkit-tests --iterations 200 --no-retry --force --no-build -f -1
> imported/w3c/web-platform-tests/xhr/send-response-upload-event-progress.htm
> --additional-env-var=JSC_slowPathAllocsBetweenGCs=10

It reproduces on WebKit2 as well.
Comment 8 Chris Dumez 2020-03-26 11:35:56 PDT
This seems to indicate that the JS wrapper for the XMLHttpRequestUpload object has been collected by the time we try and dispatch the JS event.

Normally, the XMLHttpRequestUpload wrapper is kept alive by the XMLHttpRequest wrapper via this visit method:

void JSXMLHttpRequest::visitAdditionalChildren(SlotVisitor& visitor)
{
    if (auto* upload = wrapped().optionalUpload())
        visitor.addOpaqueRoot(upload);

    if (auto* responseDocument = wrapped().optionalResponseXML())
        visitor.addOpaqueRoot(responseDocument);
}

and this generated isReachable code for JSXMLHttpRequestUpload:
bool JSXMLHttpRequestUploadOwner::isReachableFromOpaqueRoots(JSC::Handle<JSC::Unknown> handle, void*, SlotVisitor& visitor, const char** reason)
{
    auto* jsXMLHttpRequestUpload = jsCast<JSXMLHttpRequestUpload*>(handle.slot()->asCell());
    if (jsXMLHttpRequestUpload->wrapped().isFiringEventListeners()) {
        if (UNLIKELY(reason))
            *reason = "EventTarget firing event listeners";
        return true;
    }
    XMLHttpRequestUpload* root = &jsXMLHttpRequestUpload->wrapped();
    if (UNLIKELY(reason))
        *reason = "Reachable from XMLHttpRequestUpload";
    return visitor.containsOpaqueRoot(root);
}
Comment 9 Chris Dumez 2020-03-26 11:49:59 PDT
The generated bindings code for the upload.onprogress setter looks reasonable:

static inline bool setJSXMLHttpRequestEventTargetOnprogressSetter(JSGlobalObject& lexicalGlobalObject, JSXMLHttpRequestEventTarget& thisObject, JSValue value, ThrowScope& throwScope)
{
    UNUSED_PARAM(lexicalGlobalObject);
    UNUSED_PARAM(throwScope);
    setEventHandlerAttribute(lexicalGlobalObject, thisObject, thisObject.wrapped(), eventNames().progressEvent, value);

    VM& vm = JSC::getVM(&lexicalGlobalObject);
    vm.heap.writeBarrier(&thisObject, value);
    ensureStillAliveHere(value);

    return true;
}
Comment 10 Chris Dumez 2020-03-26 12:12:39 PDT
Created attachment 394636 [details]
Patch
Comment 11 Geoffrey Garen 2020-03-26 13:15:43 PDT
Comment on attachment 394636 [details]
Patch

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

r=me

> Source/WebCore/ChangeLog:10
> +        have any relevant event listeners. However, the XMLHttpRequestUpload's wrapper lifetime is tried

tied

> Source/WebCore/ChangeLog:13
> +        relevant listener, even though XMLHttpRequestUpload may have a relevant event listeners. We would

listener

> Source/WebCore/xml/XMLHttpRequest.cpp:1188
>      switch (readyState()) {

Does the readyState change to DONE before or after we fire event listeners? (It might be a problem if the answer is 'before'.)
Comment 12 Alexey Proskuryakov 2020-03-26 13:16:33 PDT
Comment on attachment 394636 [details]
Patch

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

> LayoutTests/http/wpt/xhr/send-response-upload-event-progress-agressive-gc.htm:1
> +<!DOCTYPE html><!-- webkit-test-runner [ jscOptions=--slowPathAllocsBetweenGCs=10 ] -->

Are wpt tests supposed to be upstreamed? This one obviously can't.

I remain very skeptical about adding copies of tests with slowPathAllocsBetweenGCs. That's a high cost for catching issues that we would catch anyway post-commit.
Comment 13 Chris Dumez 2020-03-26 13:20:10 PDT
(In reply to Alexey Proskuryakov from comment #12)
> Comment on attachment 394636 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=394636&action=review
> 
> > LayoutTests/http/wpt/xhr/send-response-upload-event-progress-agressive-gc.htm:1
> > +<!DOCTYPE html><!-- webkit-test-runner [ jscOptions=--slowPathAllocsBetweenGCs=10 ] -->
> 
> Are wpt tests supposed to be upstreamed? This one obviously can't.
> 
> I remain very skeptical about adding copies of tests with
> slowPathAllocsBetweenGCs. That's a high cost for catching issues that we
> would catch anyway post-commit.

Ok, I can drop the slowPathAllocsBetweenGCs test. I think Saam was the one who suggested I add such test in a previous review.
Comment 14 Chris Dumez 2020-03-26 13:24:03 PDT
Created attachment 394652 [details]
Patch
Comment 15 EWS 2020-03-26 14:33:38 PDT
Committed r259080: <https://trac.webkit.org/changeset/259080>

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