Bug 112418 – FrameLoaderClient::assignIdentifierToInitialRequest() not called for the main resource when loaded from the memory cache

• Component: Page Loading
• Status: RESOLVED FIXED

[Manuel Rego Casasnovas]

To reproduce the issue you can do the following steps in Minibrowser:
1) Go to http://www.igalia.com
2) Go to http://www.webkit.org
3) Go to http://www.igalia.com
4) Go to http://www.webkit.org
5) Click back button

If you add a listener to "load-changed" signal, you'll see that in the first 4 cases you receive the signal 3 times for each one with status: WEBKIT_LOAD_STARTED, WEBKIT_LOAD_COMMITTED and WEBKIT_LOAD_FINISHED.

However when you click back you'll only get the signal 1 time with status: WEBKIT_LOAD_STARTED.

Then if you load a different page, you'll get the signal 5 times. The 2 pending (WEBKIT_LOAD_COMMITTED and WEBKIT_LOAD_FINISHED) and the normal ones (WEBKIT_LOAD_STARTED, WEBKIT_LOAD_COMMITTED and WEBKIT_LOAD_FINISHED).

I'm only able to reproduce it in the tests using a custom scheme URI, for example the following diff will get stuck, as the load after webkit_web_view_go_back() never finishes:
diff --git a/Source/WebKit2/UIProcess/API/gtk/tests/TestWebKitWebContext.cpp b/Source/WebKit2/UIProcess/API/gtk/tests/TestWebKitWebContext.cpp
index 185c06c..9793f68 100644
--- a/Source/WebKit2/UIProcess/API/gtk/tests/TestWebKitWebContext.cpp
+++ b/Source/WebKit2/UIProcess/API/gtk/tests/TestWebKitWebContext.cpp
@@ -179,6 +179,14 @@ static void testWebContextURIScheme(URISchemeTest* test, gconstpointer)
     test->registerURISchemeHandler("foo", kBarHTML, strlen(kBarHTML), "text/html");
     test->loadURI("foo:blank");
     test->waitUntilLoadFinished();
+    test->loadURI("foo:other");
+    test->waitUntilLoadFinished();
+    test->loadURI("foo:blank");
+    test->waitUntilLoadFinished();
+    test->loadURI("foo:other");
+    test->waitUntilLoadFinished();
+    webkit_web_view_go_back(test->m_webView);
+    test->waitUntilLoadFinished();
     size_t mainResourceDataSize = 0;
     const char* mainResourceData = test->mainResourceData(mainResourceDataSize);
     g_assert_cmpint(mainResourceDataSize, ==, strlen(kBarHTML));

[Manuel Rego Casasnovas]

(In reply to comment #0)
> I'm only able to reproduce it in the tests using a custom scheme URI, for example the following diff will get stuck, as the load after webkit_web_view_go_back() never finishes:
> diff --git a/Source/WebKit2/UIProcess/API/gtk/tests/TestWebKitWebContext.cpp b/Source/WebKit2/UIProcess/API/gtk/tests/TestWebKitWebContext.cpp
> index 185c06c..9793f68 100644
> --- a/Source/WebKit2/UIProcess/API/gtk/tests/TestWebKitWebContext.cpp
> +++ b/Source/WebKit2/UIProcess/API/gtk/tests/TestWebKitWebContext.cpp
> @@ -179,6 +179,14 @@ static void testWebContextURIScheme(URISchemeTest* test, gconstpointer)
>      test->registerURISchemeHandler("foo", kBarHTML, strlen(kBarHTML), "text/html");
>      test->loadURI("foo:blank");
>      test->waitUntilLoadFinished();
> +    test->loadURI("foo:other");
> +    test->waitUntilLoadFinished();
> +    test->loadURI("foo:blank");
> +    test->waitUntilLoadFinished();
> +    test->loadURI("foo:other");
> +    test->waitUntilLoadFinished();
> +    webkit_web_view_go_back(test->m_webView);
> +    test->waitUntilLoadFinished();
>      size_t mainResourceDataSize = 0;
>      const char* mainResourceData = test->mainResourceData(mainResourceDataSize);
>      g_assert_cmpint(mainResourceDataSize, ==, strlen(kBarHTML));

BTW, you'll have to comment out the g_assert_cmpstr() in LoadTrackingTest::loadChangedCallback() otherwise the test will fail before it gets stuck.

[Manuel Rego Casasnovas]

I've just found where the load gets stuck, the problem is in WebKitWebView::webkitWebViewLoadChanged() because of priv->waitingForMainResource is set to TRUE. Then COMMITTED signal is not emitted.

[Manuel Rego Casasnovas]

(In reply to comment #2)
> I've just found where the load gets stuck, the problem is in WebKitWebView::webkitWebViewLoadChanged() because of priv->waitingForMainResource is set to TRUE. Then COMMITTED signal is not emitted.

I've been debugging it and I've more info:
* In WebKitWebView the reason why priv->waitingForMainResource is TRUE is because of priv->mainResource is NULL (as it was set in WebKitWebView::webkitWebViewLoadChanged() when WEBKIT_LOAD_STARTED was received).
* priv->mainResource is NULL because of WebKitWebView::webkitWebViewResourceLoadStarted() is never called. Which means that DidInitiateLoadForResource is never received.

The process when we click the back button is different because of it's loading a page from cache, that means that it's using DidInitiateLoadForResource is never received and it doesn't seem expected to be received.

In FrameLoader::loadProvisionalItemFromCachedPage() you can see that the first one calls startLoadingMainResource() which ends up sending the message DidInitiateLoadForResource. However FrameLoader::continueLoadAfterWillSubmitForm() doesn't do it.

We should find a way to know if we're loading a page or not from cache in order to in order to avoid mark the WebView as waitingForMainResource in webkitWebViewLoadChanged().

[Manuel Rego Casasnovas]

(In reply to comment #0)
> To reproduce the issue you can do the following steps in Minibrowser:
> 1) Go to http://www.igalia.com
> 2) Go to http://www.webkit.org
> 3) Go to http://www.igalia.com
> 4) Go to http://www.webkit.org
> 5) Click back button
> 
> If you add a listener to "load-changed" signal, you'll see that in the first 4 cases you receive the signal 3 times for each one with status: WEBKIT_LOAD_STARTED, WEBKIT_LOAD_COMMITTED and WEBKIT_LOAD_FINISHED.
> 
> However when you click back you'll only get the signal 1 time with status: WEBKIT_LOAD_STARTED.
> 
> Then if you load a different page, you'll get the signal 5 times. The 2 pending (WEBKIT_LOAD_COMMITTED and WEBKIT_LOAD_FINISHED) and the normal ones (WEBKIT_LOAD_STARTED, WEBKIT_LOAD_COMMITTED and WEBKIT_LOAD_FINISHED).

Ok, it seems normal that the signal is received 5 times here as WebKitWebView::webkitWebViewEmitDelayedLoadEvents() is called when WEBKIT_LOAD_STARTED is received for the next request.

[Manuel Rego Casasnovas]

(In reply to comment #3)
> (In reply to comment #2)
> > I've just found where the load gets stuck, the problem is in WebKitWebView::webkitWebViewLoadChanged() because of priv->waitingForMainResource is set to TRUE. Then COMMITTED signal is not emitted.
> 
> I've been debugging it and I've more info:
> * In WebKitWebView the reason why priv->waitingForMainResource is TRUE is because of priv->mainResource is NULL (as it was set in WebKitWebView::webkitWebViewLoadChanged() when WEBKIT_LOAD_STARTED was received).
> * priv->mainResource is NULL because of WebKitWebView::webkitWebViewResourceLoadStarted() is never called. Which means that DidInitiateLoadForResource is never received.
> 
> The process when we click the back button is different because of it's loading a page from cache, that means that it's using DidInitiateLoadForResource is never received and it doesn't seem expected to be received.
> 
> In FrameLoader::loadProvisionalItemFromCachedPage() you can see that the first one calls startLoadingMainResource() which ends up sending the message DidInitiateLoadForResource. However FrameLoader::continueLoadAfterWillSubmitForm() doesn't do it.
> 
> We should find a way to know if we're loading a page or not from cache in order to in order to avoid mark the WebView as waitingForMainResource in webkitWebViewLoadChanged().

I think that a possible solution would be only that in WebKitWebView::webkitWebViewLoadChanged() we mark priv->waitingForMainResource as TRUE only if priv->resource is NULL and the history item was not in cache.

[Manuel Rego Casasnovas]

Created attachment 193329 [details]
Idea to fix the problem

This is just an idea about how to fix the patch, it doesn't work as isInPageCache() is not defined in webkit_back_forward_list_item_is_in_page_cache(). I don't know yet where I should define it to make it work properly (I guess that maybe Source/WebKit2/Shared/WebBackForwardListItem.[h|cpp] could be the place but it didn't work for me yet).

The sole intention of this attachment  is to show you my idea, please take into account that it could be completely wrong :-)

[Manuel Rego Casasnovas]

Just to give more information the code related with this issue was introduced in bug #91482.

Reading the bug it seems that is mandatory to wait for the main resource so my previous idea has not any sense. Maybe we need to find a way to get the main resource in this case as WebKitWebView::webkitWebViewResourceLoadStarted() is never called in this situation as explained before.

[Manuel Rego Casasnovas]

Another idea could be to call webkitWebViewEmitDelayedLoadEvents() when webkitWebViewLoadChanged() is called with WEBKIT_LOAD_FINISHED, however I'm not sure if the main resource is available at that point.

[Carlos Garcia Campos]

The problem is that when the main resource is loaded from the memory cache, the callback assignIdentifierToInitialRequest() is not called, so from the API point of view the main resource load never starts. 

This happens because when the main resource is loaded from the memory cache the response is not added to the ResponseVector of the document loader, so that when committing the provisional load the remaining delegate messages are not called because the ResponseVector of the document loader is empty. When the main resource is loaded from the memory cache, there's no resource loader, and the client is notified about the response using ResourceLoadNotifier::dispatchDidReceiveResponse() directly instead of ResourceLoadNotifier::didReceiveResponse() which is the one adding the response to the ResponseVector of the document loader. So, the problem can be fixed by adding the response to the ResponseVector before calling dispatchDidReceiveResponse() when loading the main resource without a resource loader.

Reassigning to Page Loading since this is a regression in the WebCore loader.

[Carlos Garcia Campos]

Btw, the problem in your example only happens when loading igalia.com from the bf list because the main resource is cached, while in webkit.org it isn't.

[Carlos Garcia Campos]

Created attachment 193463 [details]
Patch

[Brady Eidson]

Comment on attachment 193463 [details]
Patch

This is the type of subtle loader quirk that we need to have tests for.

[Nate Chapin]

Comment on attachment 193463 [details]
Patch

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

> Source/WebCore/loader/MainResourceLoader.cpp:444
> +    if (m_identifierForLoadWithoutResourceLoader) {
> +        m_documentLoader->addResponse(r);
>          frameLoader()->notifier()->dispatchDidReceiveResponse(documentLoader(), identifier(), m_response, 0);
> +    }

Would it be better to fix this by moving the addResponse() call in ResourceLoadNotifier to dispatchDidReceiveResponse() from didReceiveResponse()?

[Carlos Garcia Campos]

Comment on attachment 193463 [details]
Patch

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

>> Source/WebCore/loader/MainResourceLoader.cpp:444
>> +    }
> 
> Would it be better to fix this by moving the addResponse() call in ResourceLoadNotifier to dispatchDidReceiveResponse() from didReceiveResponse()?

hmm, this is the only case where we are using dispatchDidReceiveResponse() directly, so it would work, but in ResourceLoadNotifier dispatchDidReceiveResponse() is also called from sendRemainingDelegateMessages(), do we want to add the response in that case too?

[Nate Chapin]

8(In reply to comment #14)
> (From update of attachment 193463 [details])
> View in context: https://bugs.webkit.org/attachment.cgi?id=193463&action=review
> 
> >> Source/WebCore/loader/MainResourceLoader.cpp:444
> >> +    }
> > 
> > Would it be better to fix this by moving the addResponse() call in ResourceLoadNotifier to dispatchDidReceiveResponse() from didReceiveResponse()?
> 
> hmm, this is the only case where we are using dispatchDidReceiveResponse() directly, so it would work, but in ResourceLoadNotifier dispatchDidReceiveResponse() is also called from sendRemainingDelegateMessages(), do we want to add the response in that case too?

I would guess that we do, but I'm not absolutely sure.

[Manuel Rego Casasnovas]

Created attachment 194087 [details]
Patch

Adding test to check this issue, uploading it to see the result of EWSs in different platforms (specially the ones passing tests like Chromium and Mac). I'm not sure if the test is right or you were expecting something different, please let me know what do you think about it.

[WebKit Review Bot]

Comment on attachment 194087 [details]
Patch

Attachment 194087 [details] did not pass chromium-ews (chromium-xvfb):
Output: http://webkit-commit-queue.appspot.com/results/17181657

New failing tests:
loader/go-back-cached-page.html

[Manuel Rego Casasnovas]

Created attachment 194098 [details]
Patch

I forgot to include the -expected files in the previous patch. Sorry for the noise.

[Build Bot]

Comment on attachment 194098 [details]
Patch

Attachment 194098 [details] did not pass mac-ews (mac):
Output: http://webkit-commit-queue.appspot.com/results/17210714

New failing tests:
loader/go-back-cached-page.html

[Manuel Rego Casasnovas]

Created attachment 194387 [details]
Patch

Providing new -expected file for Mac port, let's see if this time it passes in the EWS.

[Build Bot]

Comment on attachment 194387 [details]
Patch

Attachment 194387 [details] did not pass mac-ews (mac):
Output: http://webkit-commit-queue.appspot.com/results/17220580

New failing tests:
loader/go-back-cached-page.html

[Build Bot]

Created attachment 194527 [details]
Archive of layout-test-results from webkit-ews-05

The attached test failures were seen while running run-webkit-tests on the mac-ews.
Bot: webkit-ews-05  Port: <class 'webkitpy.common.config.ports.MacPort'>  Platform: Mac OS X 10.8.2

[Manuel Rego Casasnovas]

Created attachment 194535 [details]
Patch

Upload new rebaseline for Mac port.

[Manuel Rego Casasnovas]

Created attachment 197000 [details]
Patch

Removed rebaseline for chromium as the LayoutTets folder has been already cleaned up.

[Brady Eidson]

Comment on attachment 197000 [details]
Patch

Thanks for following up with a test.

This might sound like a silly nit pick, but it will help avoid confusion in the future:  The test name and text sounds too much like it is referring to the page cache, when we're really talking about the resource cache.

Anywhere you mention "cached page" can you please mention "cached main resource" instead?

[Manuel Rego Casasnovas]

Created attachment 197215 [details]
Patch

Thanks for the review. I've renamed the files accordingly and also changed the messages where I was talking about cached page instead of cached main resource.

[Darin Adler]

Comment on attachment 197215 [details]
Patch

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

> Source/WebCore/loader/DocumentLoader.cpp:610
> +        addResponse(response);
>          frameLoader()->notifier()->dispatchDidReceiveResponse(this, m_identifierForLoadWithoutResourceLoader, m_response, 0);

A little strange to use response on one line and m_response on the next to refer to the same object.

[Carlos Garcia Campos]

Committed r148182: <http://trac.webkit.org/changeset/148182>

[Alexey Proskuryakov]

Comment on attachment 197215 [details]
Patch

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

> LayoutTests/loader/go-back-cached-main-resource.html:36
> +                target.postMessage('navigate-back', '*');
> +                // Wait a bit for resource load callbacks
> +                setTimeout(function () {

It is expected that the page does not get an onload when being restored from page cache, so a 'first-page' message is not sent.

A better way to check for page being restored from page cache is to handle pageshow event on it.

[Manuel Rego Casasnovas]

(In reply to comment #29)
> (From update of attachment 197215 [details])
> View in context: https://bugs.webkit.org/attachment.cgi?id=197215&action=review
> 
> > LayoutTests/loader/go-back-cached-main-resource.html:36
> > +                target.postMessage('navigate-back', '*');
> > +                // Wait a bit for resource load callbacks
> > +                setTimeout(function () {
> 
> It is expected that the page does not get an onload when being restored from page cache, so a 'first-page' message is not sent.
> 
> A better way to check for page being restored from page cache is to handle pageshow event on it.

Thanks for the suggestion, I've tried to improve the test in a different bug #116670.