Bug 188728

Summary: Various IndexDB tests abandon documents
Product: WebKit Reporter: Simon Fraser (smfr) <simon.fraser>
Component: DOMAssignee: youenn fablet <youennf>
Status: RESOLVED FIXED    
Severity: Normal CC: achristensen, alecflett, ap, beidson, cdumez, commit-queue, ews, ggaren, jsbell, sihui_liu, simon.fraser, tsavell, webkit-bug-importer, wenson_hsieh, youennf
Priority: P2 Keywords: InRadar
Version: WebKit Nightly Build   
Hardware: Unspecified   
OS: Unspecified   
See Also: https://bugs.webkit.org/show_bug.cgi?id=188937
https://bugs.webkit.org/show_bug.cgi?id=188938
https://bugs.webkit.org/show_bug.cgi?id=189018
Bug Depends on:    
Bug Blocks: 186214    
Attachments:
Description Flags
Patch
none
Patch
none
Patch
none
Rebased
none
Patch for landing youennf: commit-queue+

Description Simon Fraser (smfr) 2018-08-18 17:06:11 PDT
Tests like imported/w3c/IndexedDB-private-browsing/cursor-overloads.html, imported/w3c/IndexedDB-private-browsing/idbcursor_advance_index.html, and others abandon the main document (bug 186214). I don't see any suspicious-looking retain stacks in C++, so I suspect this might be a GC-world issue.
Comment 1 Simon Fraser (smfr) 2018-08-22 15:17:49 PDT
A bit confused by this one. The Document is released in MiniBrowser (by an EventHandler being GC'd), but never in WebKitTestRunner even when followed by other tests and GCing.
Comment 2 Simon Fraser (smfr) 2018-08-22 18:51:03 PDT
GC heap inspector to the rescue:

HTMLDocument cell 0x42775c060 wrapped 0x42c202400 “http://localhost:8800/IndexedDB/value.htm”Show all paths—3 steps from IDBOpenDBRequest cell 0x42775c3f0 wrapped 0x42d97c3d0 (GC root—Weak sets, ActiveDOMObject with pending activity)
IDBOpenDBRequest cell 0x42775c3f0 wrapped 0x42d97c3d0 (GC root—Weak sets, ActiveDOMObject with pending activity)Internal 0
Structure cell 0x42d7a0500 “IDBOpenDBRequest”Internal 0
Window cell 0x4277d8fb0 Variable document
HTMLDocument cell 0x42775c060 wrapped 0x42c202400 “http://localhost:8800/IndexedDB/value.htm
Comment 3 Simon Fraser (smfr) 2018-08-22 19:08:19 PDT
The IDBRequest that is always active is a "blocked" event.
Comment 4 Simon Fraser (smfr) 2018-08-22 19:39:07 PDT
The test triggers the call to IDBConnectionToServer::deleteDatabase(), but we never get the IDBConnectionToServer::didDeleteDatabase() message back (unlike in MiniBrowser).
Comment 5 Simon Fraser (smfr) 2018-08-22 20:54:29 PDT
I think what's happening here is this:

1. The test runs, and says it's done, but there are still a bunch of DB operations pending.
2. In WebKtTestRunner, we immediately load about:blank. This load causes us to call IDBRequest::stop() on several IDB requests:

1   0x1f1621f75 WebCore::IDBRequest::stop()
2   0x1f219fbd5 auto WebCore::ScriptExecutionContext::stopActiveDOMObjects()::$_5::operator()<WebCore::ActiveDOMObject>(WebCore::ActiveDOMObject&) const
3   0x1f219fb84 WTF::Function<WebCore::ScriptExecutionContext::ShouldContinue (WebCore::ActiveDOMObject&)>::CallableWrapper<WebCore::ScriptExecutionContext::stopActiveDOMObjects()::$_5>::call(WebCore::ActiveDOMObject&)
4   0x1f2187060 WTF::Function<WebCore::ScriptExecutionContext::ShouldContinue (WebCore::ActiveDOMObject&)>::operator()(WebCore::ActiveDOMObject&) const
5   0x1f2186cb3 WebCore::ScriptExecutionContext::forEachActiveDOMObject(WTF::Function<WebCore::ScriptExecutionContext::ShouldContinue (WebCore::ActiveDOMObject&)> const&) const
6   0x1f2187294 WebCore::ScriptExecutionContext::stopActiveDOMObjects()
7   0x1f1fea655 WebCore::Document::stopActiveDOMObjects()
8   0x1f1fe9e8c WebCore::Document::prepareForDestruction()
9   0x1f2a0d620 WebCore::Frame::setView(WTF::RefPtr<WebCore::FrameView, WTF::DumbPtrTraits<WebCore::FrameView> >&&)
10  0x1f2a1194b WebCore::Frame::createView(WebCore::IntSize const&, WebCore::Color const&, bool, WebCore::IntSize const&, WebCore::IntRect const&, bool, WebCore::ScrollbarMode, bool, WebCore::ScrollbarMode, bool)
11  0x10b9039da WebKit::WebFrameLoaderClient::transitionToCommittedForNewPage()
12  0x1f2846955 WebCore::FrameLoader::transitionToCommitted(WebCore::CachedPage*)
13  0x1f2845990 WebCore::FrameLoader::commitProvisionalLoad()
14  0x1f27ea8bc WebCore::DocumentLoader::commitIfReady()

3. We get to IDBConnectionToServer::didDeleteDatabase() with IDBResultType::DeleteDatabaseSuccess, but m_contextStopped is true, so we never enqueue a "success" event.

This leaves us in a state where a "blocked" event is never cleared, and we have an ActiveDOMObject which remains active, which keeps the Document alive.

Maybe IDBRequest::stop() should set m_hasPendingActivity to false?
Comment 6 Radar WebKit Bug Importer 2018-08-23 11:30:06 PDT
<rdar://problem/43651095>
Comment 7 Simon Fraser (smfr) 2018-08-23 11:57:15 PDT
How to reproduce in MiniBrowser:
1. Apply this patch to the test:
diff --git a/LayoutTests/imported/w3c/web-platform-tests/IndexedDB/value.htm b/LayoutTests/imported/w3c/web-platform-tests/IndexedDB/value.htm
index 36e8339524852590d52ce2275a9f0c0f372f6d31..397ca733f74360321db7dd4ae042ad718615d923 100644
--- a/LayoutTests/imported/w3c/web-platform-tests/IndexedDB/value.htm
+++ b/LayoutTests/imported/w3c/web-platform-tests/IndexedDB/value.htm
@@ -27,6 +27,7 @@ function value(value, _instanceof) {
             {
                 assert_true(e.target.result instanceof _instanceof, "instanceof")
                 t.done();
+                window.location.href = 'about:blank';
             });
         });
     };

2. Start the http server: ./Tools/Scripts/run-webkit-httpd
3. Load the test in MiniBrowser: http://localhost:8800/IndexedDB/value.htm
4. Fire a memory warning (in Terminal: "notifyutil -p org.WebKit.lowMemory")
5. Dump the list of live documents (in Terminal: "notifyutil -p com.apple.WebKit.showAllDocuments")

http://localhost:8800/IndexedDB/value.htm will be listed there.
Comment 8 youenn fablet 2018-08-23 15:24:04 PDT
Several IDB objects implement hasPendingActivity.
IDBRequest and IDBCursor at least may still returning true to hasPendingActivity even when stopped. This should probably not be the case.
Comment 9 youenn fablet 2018-08-24 09:52:36 PDT
Created attachment 348018 [details]
Patch
Comment 10 Simon Fraser (smfr) 2018-08-24 10:11:10 PDT
Comment on attachment 348018 [details]
Patch

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

> Source/WebCore/testing/Internals.idl:668
> +    sequence<DOMString> documentURLs();

I don't think you need to add this. Instead, use:

    unsigned long long documentIdentifier(Document document);
    boolean isDocumentAlive(unsigned long long documentIdentifier);
Comment 11 youenn fablet 2018-08-24 10:36:33 PDT
Doing some more code inspection, I can see several reasons why IDBRequest::m_hasPendingActivity would remain true:
1. IDBOpenDBRequest::requestCompleted is called after the request is stopped. We then never set back m_hasPendingActivity to false since we do not want to call enqueueEvent. This could be fixed by adding something like a IDBRequest::requestCompletedAfterContextStopped to do the cleanup.
2. IDBRequest::dispatchEvent has a code path where it will reset m_hasPendingActivity to true (in case of upgrade needed or blocked event). I do not see how in that case we can ensure that a new transaction will be created so that IDBRequest::dispatchEvent would be called again to set m_hasPendingActivity to false again.

The fact that m_hasPendingActivity is true by default is also a potential source of issue but from what I see, we are always creating a request and then doing some transaction, so this does not seem to be a possible cause now.

There is the context of a TransactionOperation that has a ref to a IDBRequest.
Maybe IDBRequest::m_hasPendingActivity should be true as long as a TransactionOperation holds a ref to it.
That would require to better understand case 2.
Comment 12 youenn fablet 2018-08-24 10:36:55 PDT
(In reply to Simon Fraser (smfr) from comment #10)
> Comment on attachment 348018 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=348018&action=review
> 
> > Source/WebCore/testing/Internals.idl:668
> > +    sequence<DOMString> documentURLs();
> 
> I don't think you need to add this. Instead, use:
> 
>     unsigned long long documentIdentifier(Document document);
>     boolean isDocumentAlive(unsigned long long documentIdentifier);

ok, will do.
Comment 13 youenn fablet 2018-08-24 10:42:20 PDT
To make code more robust, we could envision to make all ActiveDOMObjects be collectable once their context is stopped/preparing for destruction. That could be done in the binding generator, JSXXOwner::isReachableFromOpaqueRoots.

Looking at all ActiveDOMObject reimplementing hasPendingActivity, they seem to follow this strategy.
For the other ActiveDOMObjects, they usually rely on setPendingActivity/unsetPendingActivity so need to make sure they mirror setPendingActivity calls with un setPendingActivity calls.
Comment 14 youenn fablet 2018-08-24 10:57:11 PDT
Created attachment 348023 [details]
Patch
Comment 15 youenn fablet 2018-08-24 11:51:49 PDT
Created attachment 348031 [details]
Patch
Comment 16 Simon Fraser (smfr) 2018-08-24 12:54:14 PDT
Comment on attachment 348031 [details]
Patch

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

> Source/WebCore/ChangeLog:9
> +        Some IDB objects implement hasPendingActivity but there are some possibilities that they continue returning true after being stopped. 

I think you should explain these scenarios in more detail here.

> Source/WebCore/ChangeLog:11
> +        This ensures that they can be garbage collected once their document is preparing for destruction.

The dependency is the other way around: they have to be GC'd before the Document can be destroyed.

> Source/WebCore/Modules/indexeddb/IDBCursor.cpp:372
> +    return !m_contextStopped && m_outstandingRequestCount;

Don't we need to wait for outstanding requests to complete (either after finishing, or being canceled)? I'm worried that allowing IDBCursor's to be GC'd while things are still happening could corrupt databases.

> Source/WebCore/Modules/indexeddb/IDBRequest.cpp:269
> +    return !m_contextStopped && m_hasPendingActivity;

Ditto.
Comment 17 youenn fablet 2018-08-24 13:51:25 PDT
> > Source/WebCore/ChangeLog:9
> > +        Some IDB objects implement hasPendingActivity but there are some possibilities that they continue returning true after being stopped. 
> 
> I think you should explain these scenarios in more detail here.

OK

> > Source/WebCore/ChangeLog:11
> > +        This ensures that they can be garbage collected once their document is preparing for destruction.
> 
> The dependency is the other way around: they have to be GC'd before the
> Document can be destroyed.

I was meaning Document::prepareForDestruction, not Document destructor.

> > Source/WebCore/Modules/indexeddb/IDBCursor.cpp:372
> > +    return !m_contextStopped && m_outstandingRequestCount;
> 
> Don't we need to wait for outstanding requests to complete (either after
> finishing, or being canceled)? I'm worried that allowing IDBCursor's to be
> GC'd while things are still happening could corrupt databases.

AFAIUI, the point of hasPendingActivity implementation here is that the objects will not be GCed so that we can dispatch their events properly. Since there is no point in dispatching events after they are stopped, the change seems fine to me.

IDBCursor and IDBRequest hasPendingActivity implementation is not to ensure objects get not deallocated.
For that purpose, other objects are taking Ref to these objects.
For instance, nobody is storing a raw reference/pointer to IDBCursor.
IDBCursor does take a raw pointer to IDBRequest but this gets cleared in IDBRequest destructor.

In general, I do not think we should count on GC to keep the objects alive when we are waiting for some async task.
Instead, the async task should take a Ref until being completed.

In the case of IDBCursor, we could try to stick with m_outstandingRequestCount only although I do not see a huge benefit there.
We would probably just need to clear IDBRequest::m_cursorRequestNotifier in IDBRequest::stop.
We could add an ASSERT to make sure that m_outstandingRequestCount is 0 once stopped.

> > Source/WebCore/Modules/indexeddb/IDBRequest.cpp:269
> > +    return !m_contextStopped && m_hasPendingActivity;
> 
> Ditto.

For this one, I do not have a better plan right now.
I do not understand IDB enough yet to see why m_hasPendingActivity can be set back to true in IDBRequest::dispatchEvent.
Again, my interpretation is that it only has to do with event dispatching, not keeping the C++ object alive.
Comment 18 Alex Christensen 2018-08-27 08:47:19 PDT
Comment on attachment 348031 [details]
Patch

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

>> Source/WebCore/Modules/indexeddb/IDBCursor.cpp:372
>> +    return !m_contextStopped && m_outstandingRequestCount;
> 
> Don't we need to wait for outstanding requests to complete (either after finishing, or being canceled)? I'm worried that allowing IDBCursor's to be GC'd while things are still happening could corrupt databases.

This needs a new patch after making IDBCursor no longer an ActiveDOMObject
Comment 19 youenn fablet 2018-08-27 12:36:42 PDT
Created attachment 348188 [details]
Rebased
Comment 20 Wenson Hsieh 2018-08-27 13:35:40 PDT
Comment on attachment 348188 [details]
Rebased

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

> Source/WebCore/ChangeLog:11
> +        This is also the case for requests that emits upgradenneeded or blocked events.

Nit - upgradenneeded!
Comment 21 youenn fablet 2018-08-27 15:55:27 PDT
Doing some more tests, IDBDatabase also has a similar risk, let's handle it in a separate patch.
Comment 22 youenn fablet 2018-08-27 15:59:45 PDT
Created attachment 348226 [details]
Patch for landing
Comment 23 WebKit Commit Bot 2018-08-27 16:41:19 PDT
Comment on attachment 348226 [details]
Patch for landing

Clearing flags on attachment: 348226

Committed r235410: <https://trac.webkit.org/changeset/235410>
Comment 24 WebKit Commit Bot 2018-08-27 16:41:21 PDT
All reviewed patches have been landed.  Closing bug.
Comment 25 Truitt Savell 2018-09-04 17:03:49 PDT
Looks like the test
http/tests/IndexedDB/collect-IDB-objects.https.html

introduced in https://trac.webkit.org/changeset/235410/webkit

has been flakey from the start

Test History:
http://webkit-test-results.webkit.org/dashboards/flakiness_dashboard.html#showAllRuns=true&tests=http%2Ftests%2FIndexedDB%2Fcollect-IDB-objects.https.html

Diff:
--- /Volumes/Data/slave/highsierra-release-tests-wk1/build/layout-test-results/http/tests/IndexedDB/collect-IDB-objects.https-expected.txt
+++ /Volumes/Data/slave/highsierra-release-tests-wk1/build/layout-test-results/http/tests/IndexedDB/collect-IDB-objects.https-actual.txt
@@ -1,4 +1,4 @@
 
 
-PASS Ensuring frame document gets collected after being stopped in the middle of IDB operations 
+FAIL Ensuring frame document gets collected after being stopped in the middle of IDB operations promise_test: Unhandled rejection with value: "Test failed"