Bug 42772 – WebTiming does not take page cache into account

• Status: RESOLVED
• Resolution: FIXED
• Component: WebKit Misc.

[Simon Fraser (smfr)]

After running run-webkit-tests and getting a Safari browser showing a page with test results, with some failures, if I click on a test result diff, and then click Back, I get:

ASSERTION FAILED: !timing->unloadEventEnd
(/Volumes/InternalData/Development/webkit/OpenSource/WebCore/loader/FrameLoader.cpp:456 void WebCore::FrameLoader::stopLoading(WebCore::UnloadEventPolicy, WebCore::DatabasePolicy))

Stack is:

#0  0x00000001035d210e in WebCore::FrameLoader::stopLoading (this=0x11c816050, unloadEventPolicy=WebCore::UnloadEventPolicyUnloadAndPageHide, databasePolicy=WebCore::DatabasePolicyStop) at /Volumes/InternalData/Development/webkit/OpenSource/WebCore/loader/FrameLoader.cpp:456
#1  0x00000001035d24a6 in WebCore::FrameLoader::closeURL (this=0x11c816050) at /Volumes/InternalData/Development/webkit/OpenSource/WebCore/loader/FrameLoader.cpp:527
#2  0x00000001035d3d9d in WebCore::FrameLoader::transitionToCommitted (this=0x11c816050, cachedPage=@0x7fff5fbfd9d0) at /Volumes/InternalData/Development/webkit/OpenSource/WebCore/loader/FrameLoader.cpp:1983
#3  0x00000001035d4605 in WebCore::FrameLoader::commitProvisionalLoad (this=0x11c816050) at /Volumes/InternalData/Development/webkit/OpenSource/WebCore/loader/FrameLoader.cpp:1907
#4  0x00000001035d4b48 in WebCore::FrameLoader::loadProvisionalItemFromCachedPage (this=0x11c816050) at /Volumes/InternalData/Development/webkit/OpenSource/WebCore/loader/FrameLoader.cpp:3150
#5  0x00000001035d4edc in WebCore::FrameLoader::continueLoadAfterNavigationPolicy (this=0x11c816050, formState=@0x7fff5fbfdca0, shouldContinue=true) at /Volumes/InternalData/Development/webkit/OpenSource/WebCore/loader/FrameLoader.cpp:3023
#6  0x00000001035d4f9e in WebCore::FrameLoader::callContinueLoadAfterNavigationPolicy (argument=0x11c816050, request=@0x11c8d9220, formState=@0x7fff5fbfddf0, shouldContinue=true) at /Volumes/InternalData/Development/webkit/OpenSource/WebCore/loader/FrameLoader.cpp:2929
#7  0x0000000103b05921 in WebCore::PolicyChecker::checkNavigationPolicy (this=0x11c816060, request=@0x11c8d9220, loader=0x11c8d8e00, formState=@0x7fff5fbfdee0, function=0x1035d4f5a <WebCore::FrameLoader::callContinueLoadAfterNavigationPolicy(void*, WebCore::ResourceRequest const&, WTF::PassRefPtr<WebCore::FormState>, bool)>, argument=0x11c816050) at /Volumes/InternalData/Development/webkit/OpenSource/WebCore/loader/PolicyChecker.cpp:68
#8  0x00000001035d53b6 in WebCore::FrameLoader::loadWithDocumentLoader (this=0x11c816050, loader=0x11c8d8e00, type=WebCore::FrameLoadTypeBack, prpFormState=@0x7fff5fbfe210) at /Volumes/InternalData/Development/webkit/OpenSource/WebCore/loader/FrameLoader.cpp:1542
#9  0x00000001035d6251 in WebCore::FrameLoader::navigateToDifferentDocument (this=0x11c816050, item=0x11ff4c7f0, loadType=WebCore::FrameLoadTypeBack) at /Volumes/InternalData/Development/webkit/OpenSource/WebCore/loader/FrameLoader.cpp:3208
#10 0x00000001035d6874 in WebCore::FrameLoader::loadItem (this=0x11c816050, item=0x11ff4c7f0, loadType=WebCore::FrameLoadTypeBack) at /Volumes/InternalData/Development/webkit/OpenSource/WebCore/loader/FrameLoader.cpp:3311
#11 0x000000010364d8b8 in WebCore::HistoryController::recursiveGoToItem (this=0x11c8161c8, item=0x11ff4c7f0, fromItem=0x124922b30, type=WebCore::FrameLoadTypeBack) at /Volumes/InternalData/Development/webkit/OpenSource/WebCore/loader/HistoryController.cpp:580
#12 0x000000010364da10 in WebCore::HistoryController::goToItem (this=0x11c8161c8, targetItem=0x11ff4c7f0, type=WebCore::FrameLoadTypeBack) at /Volumes/InternalData/Development/webkit/OpenSource/WebCore/loader/HistoryController.cpp:224
#13 0x0000000103ade01e in WebCore::Page::goToItem (this=0x11add3530, item=0x11ff4c7f0, type=WebCore::FrameLoadTypeBack) at /Volumes/InternalData/Development/webkit/OpenSource/WebCore/page/Page.cpp:332
#14 0x0000000103ade1e5 in WebCore::Page::goBack (this=0x11add3530) at /Volumes/InternalData/Development/webkit/OpenSource/WebCore/page/Page.cpp:261
#

[Simon Fraser (smfr)]

This prevents me from browser layout test results with a debug  build.

[Adam Barth]

Yeah, this bug is super annoying to me too.  Tonyg, are you looking at it?

[Tony Gentilcore]

(In reply to comment #2)
> Yeah, this bug is super annoying to me too.  Tonyg, are you looking at it?

Yes, I'll be landing a patch to temporarily comment out the ASSERT momentarily.

[Tony Gentilcore]

I've disabled the ASSERT for now. The consequence of that ASSERT being reached is that the unloadEventEnd exposed to Web Timing is incorrect.

I'm leaving this open to track the actual fix.

[Mihai Parparita]

Created attachment 63543 [details]
testcast

[Mihai Parparita]

I've attached a reduced test case. For triggering the assert when going page 1-> page 2 -> back the requirements are for page 1 to not have an unload handler but for page 2 to have one. This makes page 1 end up in the page cache, while page 2 doesn't.

Tony, do you mind if I work on fixing this? It seems like another good (i.e. simple) initial patch for me.

[Tony Gentilcore]

(In reply to comment #6)
> I've attached a reduced test case. For triggering the assert when going page 1-> page 2 -> back the requirements are for page 1 to not have an unload handler but for page 2 to have one. This makes page 1 end up in the page cache, while page 2 doesn't.
> 
> Tony, do you mind if I work on fixing this? It seems like another good (i.e. simple) initial patch for me.

By all means. Nice reduction :-)

[Mihai Parparita]

After looking at this a bit more, it looks like the WebTiming code in general doesn't take the page cache into account at all. When we're restoring a page from the page cache, we bypass the normal loading flow (e.g. navigationStart is called in continueLoadAfterWillSubmitForm, but we exit before that in continueLoadAfterNavigationPolicy, and instead call loadProvisionalItemFromCachedPage). 

The fix might be as simple as resetting the timing data in loadProvisionalItemFromCachedPage (so that times recorded for the previous time the page was displayed aren't used) and also recording navigationStart there.

[Mihai Parparita]

Created attachment 63783 [details]
Patch

[Mihai Parparita]

Adam, can you review this (since you helped Tony and I understand what's going on in the first place)?

[Mihai Parparita]

Created attachment 63786 [details]
Patch

[Adam Barth]

Comment on attachment 63786 [details]
Patch

Looks great!  Thanks.

[Eric Seidel (no email)]

Comment on attachment 63786 [details]
Patch

Clearing flags on attachment: 63786

Committed r64939: <http://trac.webkit.org/changeset/64939>

[Eric Seidel (no email)]

All reviewed patches have been landed.  Closing bug.

[WebKit Review Bot]

http://trac.webkit.org/changeset/64939 might have broken GTK Linux 64-bit Debug

[Mihai Parparita]

This is the diff from the GTK builder of onunload-back-to-page-cache.html

-main frame "navigated" - has 1 onunload handler(s)
+main frame - has 1 onunload handler(s)

Seems like the GTK DRT doesn't report frame names quite the same way as the other DRTs. I'll modify the test to clear the frame name before exiting and file a bug about the GTK DRT (if there isn't one already).

[Adam Barth]

> Seems like the GTK DRT doesn't report frame names quite the same way as the other DRTs. I'll modify the test to clear the frame name before exiting and file a bug about the GTK DRT (if there isn't one already).

Thanks.  The other option is to make the Gtk DRT report frame names correctly.

[Mihai Parparita]

(In reply to comment #17)
> > Seems like the GTK DRT doesn't report frame names quite the same way as the other DRTs. I'll modify the test to clear the frame name before exiting and file a bug about the GTK DRT (if there isn't one already).
> 
> Thanks.  The other option is to make the Gtk DRT report frame names correctly.

I filed bug 43690 about fixing the GTK DRT, but since I don't have a Linux build environment (yet), modifying the test seems like reasonable workaround for now (bug 43692 has that).