Bug 106123

Summary: REGRESSION(r138222?): [Mac WK1] http/tests/appcache/main-resource-redirect.html asserts in WebFrameLoaderClient::dispatchDidFinishLoading
Product: WebKit Reporter: Ryosuke Niwa <rniwa>
Component: Page LoadingAssignee: Nate Chapin <japhet>
Status: RESOLVED FIXED    
Severity: Normal CC: ap, beidson, cdumez, cgarcia, eric.carlson, japhet, webkit-bug-importer, webkit.review.bot
Priority: P2 Keywords: InRadar
Version: 528+ (Nightly build)   
Hardware: Unspecified   
OS: Unspecified   
Bug Depends on: 105591    
Bug Blocks: 106137    
Attachments:
Description Flags
Patch
none
Unskip the test
none
Fix by preventing ResourceLoader from sending callbacks
ap: review-, ap: commit-queue-
Address ap's comments
none
Patch for landing none

Description Ryosuke Niwa 2013-01-04 12:05:07 PST
http://test-results.appspot.com/dashboards/flakiness_dashboard.html#group=%40ToT%20-%20webkit.org&tests=http%2Ftests%2Fappcache%2Fmain-resource-redirect.html

http://build.webkit.org/results/Apple%20MountainLion%20Debug%20WK1%20(Tests)/r138809%20(4306)/results.html

CRASHING TEST: /appcache/main-resource-redirect.html

Thread 0 Crashed:: Dispatch queue: com.apple.main-thread
0   com.apple.WebKit              	0x000000010533f7aa -[WebView(WebViewInternal) _removeObjectForIdentifier:] + 122 (WebView.mm:6229)
1   com.apple.WebKit              	0x00000001052489b1 WebFrameLoaderClient::dispatchDidFinishLoading(WebCore::DocumentLoader*, unsigned long) + 225 (WebFrameLoaderClient.mm:477)
2   com.apple.WebCore             	0x0000000106e2de7b WebCore::ResourceLoadNotifier::dispatchDidFinishLoading(WebCore::DocumentLoader*, unsigned long, double) + 91 (ResourceLoadNotifier.cpp:148)
3   com.apple.WebCore             	0x00000001069a25c3 WebCore::MainResourceLoader::didFinishLoading(double) + 147 (MainResourceLoader.cpp:529)
4   com.apple.WebCore             	0x00000001069a24f4 WebCore::MainResourceLoader::continueAfterContentPolicy(WebCore::PolicyAction, WebCore::ResourceResponse const&) + 1636 (MainResourceLoader.cpp:358)
5   com.apple.WebCore             	0x00000001069a2846 WebCore::MainResourceLoader::continueAfterContentPolicy(WebCore::PolicyAction) + 166 (MainResourceLoader.cpp:373)
6   com.apple.WebCore             	0x00000001069a278b WebCore::MainResourceLoader::callContinueAfterContentPolicy(void*, WebCore::PolicyAction) + 27 (MainResourceLoader.cpp:365)
7   com.apple.WebCore             	0x0000000106afd919 WebCore::PolicyCallback::call(WebCore::PolicyAction) + 297 (PolicyCallback.cpp:115)
8   com.apple.WebCore             	0x0000000106afe73d WebCore::PolicyChecker::continueAfterContentPolicy(WebCore::PolicyAction) + 93 (PolicyChecker.cpp:194)
9   com.apple.WebKit              	0x000000010524dfda WebFrameLoaderClient::receivedPolicyDecison(WebCore::PolicyAction) + 410 (WebFrameLoaderClient.mm:1286)
10  com.apple.WebKit              	0x0000000105252401 -[WebFramePolicyListener receivedPolicyDecision:] + 193 (WebFrameLoaderClient.mm:2025)
11  com.apple.WebKit              	0x0000000105252510 -[WebFramePolicyListener use] + 48 (WebFrameLoaderClient.mm:2041)
12  com.apple.WebKit              	0x000000010521f772 -[WebDefaultPolicyDelegate webView:decidePolicyForMIMEType:request:frame:decisionListener:] + 338 (WebDefaultPolicyDelegate.m:74)
13  com.apple.CoreFoundation      	0x00007fff8a08763c __invoking___ + 140
14  com.apple.CoreFoundation      	0x00007fff8a0874d7 -[NSInvocation invoke] + 263
15  com.apple.CoreFoundation      	0x00007fff8a0876a9 -[NSInvocation invokeWithTarget:] + 57
16  com.apple.WebKit              	0x000000010532bfa9 -[_WebSafeForwarder forwardInvocation:] + 361 (WebView.mm:3083)
17  com.apple.CoreFoundation      	0x00007fff8a082737 ___forwarding___ + 775
18  com.apple.CoreFoundation      	0x00007fff8a0823b8 _CF_forwarding_prep_0 + 232
19  com.apple.WebKit              	0x0000000105249edb WebFrameLoaderClient::dispatchDecidePolicyForResponse(void (WebCore::PolicyChecker::*)(WebCore::PolicyAction), WebCore::ResourceResponse const&, WebCore::ResourceRequest const&) + 363 (WebFrameLoaderClient.mm:723)
20  com.apple.WebCore             	0x0000000106afe6d7 WebCore::PolicyChecker::checkContentPolicy(WebCore::ResourceResponse const&, void (*)(void*, WebCore::PolicyAction), void*) + 183 (PolicyChecker.cpp:109)
21  com.apple.WebCore             	0x00000001069a2fc4 WebCore::MainResourceLoader::responseReceived(WebCore::CachedResource*, WebCore::ResourceResponse const&) + 1892 (MainResourceLoader.cpp:446)
22  com.apple.WebCore             	0x00000001069a0de4 WebCore::MainResourceLoader::handleSubstituteDataLoadNow(WebCore::RunLoopTimer<WebCore::MainResourceLoader>*) + 436 (MainResourceLoader.cpp:600)
23  com.apple.WebCore             	0x00000001069a4dc3 WebCore::RunLoopTimer<WebCore::MainResourceLoader>::fired() + 115 (RunLoopTimer.h:71)
24  com.apple.WebCore             	0x0000000106e62e40 WebCore::timerFired(__CFRunLoopTimer*, void*) + 64 (RunLoopTimerCF.cpp:52)
25  com.apple.CoreFoundation      	0x00007fff8a050da4 __CFRUNLOOP_IS_CALLING_OUT_TO_A_TIMER_CALLBACK_FUNCTION__ + 20
26  com.apple.CoreFoundation      	0x00007fff8a0508bd __CFRunLoopDoTimer + 557
27  com.apple.CoreFoundation      	0x00007fff8a036099 __CFRunLoopRun + 1513
28  com.apple.CoreFoundation      	0x00007fff8a0356b2 CFRunLoopRunSpecific + 290
29  com.apple.Foundation          	0x00007fff8702389e -[NSRunLoop(NSRunLoop) runMode:beforeDate:] + 268
30  DumpRenderTree                	0x0000000103f20839 runTest(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&) + 5017 (DumpRenderTree.mm:1381)
31  DumpRenderTree                	0x0000000103f1f42a runTestingServerLoop() + 282 (DumpRenderTree.mm:846)
32  DumpRenderTree                	0x0000000103f1ecf7 dumpRenderTree(int, char const**) + 391 (DumpRenderTree.mm:893)
Comment 1 Radar WebKit Bug Importer 2013-01-04 12:05:28 PST
<rdar://problem/12958827>
Comment 2 Ryosuke Niwa 2013-01-04 12:05:35 PST
It’s hard to tell whether this is a recent regression or something that existed for a long time.
Comment 3 Ryosuke Niwa 2013-01-04 12:09:22 PST
Oh, now I see what’s happening. http://trac.webkit.org/changeset/138782 tried to fix this crash but it didn’t.
Comment 4 Ryosuke Niwa 2013-01-04 12:12:18 PST
This is only happening in WebKit1.
Comment 5 Ryosuke Niwa 2013-01-04 12:15:15 PST
Updated test expectations in http://trac.webkit.org/changeset/138828.
Comment 6 Ryosuke Niwa 2013-01-04 17:01:29 PST
Turned out that this is an assertion failure:
- (void)_removeObjectForIdentifier:(unsigned long)identifier
{
    ASSERT(_private->identifierMap.contains(identifier)); << this guy.
    _private->identifierMap.remove(identifier);
    
    // If the identifier map is now empty it means we're no longer loading anything
    // and we should release the web view. Autorelease rather than release in order to
    // avoid re-entering this method beneath -dealloc with the same identifier. <rdar://problem/10523721>
    if (_private->identifierMap.isEmpty())
        WebCFAutorelease(self);
}
Comment 7 Carlos Garcia Campos 2013-01-05 01:46:45 PST
(In reply to comment #3)
> Oh, now I see what’s happening. http://trac.webkit.org/changeset/138782 tried to fix this crash but it didn’t.

Not exactly, they are actually different bugs. Bug #105591 fixed an assertion when the resource identifier is 0. The problem now is that for some reason, dispatchDidFailLoading() is called for a resource, but the load doesn't actually finish and dispatchDidReceiveResponse(), dispatchDidReceiveData() and dispatchDidFinishLoading() are called for the same resource after the dispatchDidFailLoading(). This is of course not expected, Mac removes the object from the map in both DidFailLoading and DidFinishLoading.
Comment 8 Carlos Garcia Campos 2013-01-05 02:57:53 PST
Created attachment 181433 [details]
Patch

The problem is that we are clearing the resource before continuing loading from the substitute data, which cancels the load.
Comment 10 Alexey Proskuryakov 2013-01-07 09:58:33 PST
Nate, Brady, who should review this?
Comment 11 Nate Chapin 2013-01-07 10:08:42 PST
Comment on attachment 181433 [details]
Patch

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

This presumably should remove main-resource-redirect.html from the relevant TestExpectations files.

> Source/WebCore/loader/MainResourceLoader.cpp:151
> +    if (m_resource) {
> +        m_resource->setLoading(false);
> +        m_resource->stopLoading();
> +    }
> +}

This is better than anything I've come up with in that it actually works, but it's still pretty hacky. I guess it's ok, though.
Comment 12 Carlos Garcia Campos 2013-01-08 01:02:05 PST
Created attachment 181668 [details]
Unskip the test

Updated patch to unskip the test
Comment 13 Build Bot 2013-01-08 02:45:37 PST
Comment on attachment 181668 [details]
Unskip the test

Attachment 181668 [details] did not pass mac-ews (mac):
Output: http://queues.webkit.org/results/15763049

New failing tests:
http/tests/appcache/manifest-containing-itself.html
Comment 14 Build Bot 2013-01-08 03:14:55 PST
Comment on attachment 181668 [details]
Unskip the test

Attachment 181668 [details] did not pass mac-ews (mac):
Output: http://queues.webkit.org/results/15757070

New failing tests:
http/tests/appcache/manifest-containing-itself.html
Comment 15 Nate Chapin 2013-01-08 12:14:44 PST
Created attachment 181725 [details]
Fix by preventing ResourceLoader from sending callbacks

The previous fix doesn't work because CachedResource::stopLoading() doesn't actually kill stop the ResourceLoader (renaming it is on my list of things to do).

It appears we can get the right behavior by temporarily suppressing resource load callbacks, which will prevent WebFrameLoaderClient from receiving 2 end-of-load callbacks.
Comment 16 Alexey Proskuryakov 2013-01-08 16:27:22 PST
Comment on attachment 181725 [details]
Fix by preventing ResourceLoader from sending callbacks

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

> Source/WebCore/loader/MainResourceLoader.cpp:185
> +        // We need to remove our reference to the CachedResource (which will probably cancel its underlying ResourceLoader)

Why is the cancellation just "probable"? If the load is not canceled now, will it be canceled later, outside the temporary DoNotSendCallbacks mode?

> Source/WebCore/loader/MainResourceLoader.cpp:192
> +        if (resourceLoader)
> +            resourceLoader->setSendCallbackPolicy(DoNotSendCallbacks);
>          clearResource();
> +        resourceLoader->setSendCallbackPolicy(SendCallbacks);

It looks wrong to have a null check the first time we dereference resourceLoader, but not the second time. If it's actually possible to not have a resourceLoader here, please add a regression test for this case.

Also, is this expected to reset policy to original value? Can we assert that SendCallbacks is actually the original value?

> Source/WebCore/ChangeLog:14
> +        (WebCore::ResourceLoader::sendCallbackPolicy): Renamed from shouldSendResourceLoadCallbacks(), returns an enum value instead of a bool.

I'm not sure why this is an improvement. A boolean gives the needed answer more directly, as evidenced by how you had to modify the call site.
Comment 17 Nate Chapin 2013-01-08 16:32:01 PST
(In reply to comment #16)
> (From update of attachment 181725 [details])
> View in context: https://bugs.webkit.org/attachment.cgi?id=181725&action=review
> 
> > Source/WebCore/loader/MainResourceLoader.cpp:185
> > +        // We need to remove our reference to the CachedResource (which will probably cancel its underlying ResourceLoader)
> 
> Why is the cancellation just "probable"? If the load is not canceled now, will it be canceled later, outside the temporary DoNotSendCallbacks mode?

There is a tiny chance that multiple iframes will be loading the same src at the same exact time. In that case, the CachedResource will have multiple clients, so calling clearResource() won't actually trigger a cancellation of the ResourceLoader via CachedRawResource::cancelIfNotFinishing().

> 
> > Source/WebCore/loader/MainResourceLoader.cpp:192
> > +        if (resourceLoader)
> > +            resourceLoader->setSendCallbackPolicy(DoNotSendCallbacks);
> >          clearResource();
> > +        resourceLoader->setSendCallbackPolicy(SendCallbacks);
> 
> It looks wrong to have a null check the first time we dereference resourceLoader, but not the second time. If it's actually possible to not have a resourceLoader here, please add a regression test for this case.

Doh, will fix.

> 
> Also, is this expected to reset policy to original value? Can we assert that SendCallbacks is actually the original value?

Will do.

> 
> > Source/WebCore/ChangeLog:14
> > +        (WebCore::ResourceLoader::sendCallbackPolicy): Renamed from shouldSendResourceLoadCallbacks(), returns an enum value instead of a bool.
> 
> I'm not sure why this is an improvement. A boolean gives the needed answer more directly, as evidenced by how you had to modify the call site.

I was thinking that this was canonicalizing things, based on some feedback on a review a couple weeks ago. I'm totally fine with removing it.
Comment 18 Alexey Proskuryakov 2013-01-08 16:39:12 PST
> There is a tiny chance that multiple iframes will be loading the same src at the same exact time. In that case, the CachedResource will have multiple clients, so calling clearResource() won't actually trigger a cancellation of the ResourceLoader via CachedRawResource::cancelIfNotFinishing().

This is probably worth explaining in a comment more directly. As well as how the switch to substitute data will happen in this case.

There is a risk associated with such detailed comments, as they tend to become wrong and misleading very quickly. But a "probably" clause in a comment is quite annoying, too.
Comment 19 Nate Chapin 2013-01-08 16:47:27 PST
Created attachment 181802 [details]
Address ap's comments
Comment 20 Alexey Proskuryakov 2013-01-08 16:57:02 PST
Comment on attachment 181802 [details]
Address ap's comments

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

> Source/WebCore/loader/MainResourceLoader.cpp:193
> +        if (resourceLoader)

I asked Nate on IRC, and he doesn't know if this can actually happen in practice. It's very confusing to have unnecessary null checks just in case, but given the urgency, I guess I can grudgingly say r=me.

> Source/WebCore/loader/ResourceLoader.h:143
> +    void setSendCallbackPolicy(SendCallbackPolicy sendLoadCallbacks)  { m_options.sendLoadCallbacks = sendLoadCallbacks; }

Extra space before '{'.
Comment 21 Nate Chapin 2013-01-08 17:04:01 PST
Created attachment 181808 [details]
Patch for landing
Comment 22 WebKit Review Bot 2013-01-08 19:32:04 PST
Comment on attachment 181808 [details]
Patch for landing

Clearing flags on attachment: 181808

Committed r139150: <http://trac.webkit.org/changeset/139150>
Comment 23 WebKit Review Bot 2013-01-08 19:32:10 PST
All reviewed patches have been landed.  Closing bug.