Bug 7693 - WebKit relies on unpredictable timing for onload events
: WebKit relies on unpredictable timing for onload events
Status: RESOLVED FIXED
: WebKit
WebKit Misc.
: 420+
: Macintosh Mac OS X 10.4
: P1 Normal
Assigned To:
:
: Regression
:
: 5122 5487 6560
  Show dependency treegraph
 
Reported: 2006-03-09 21:52 PST by
Modified: 2006-03-17 12:30 PST (History)


Attachments
A test case for the bug (171 bytes, text/plain)
2006-03-09 22:46 PST, Daniel Peebles
no flags Details
Reduction (249 bytes, text/html)
2006-03-10 06:36 PST, mitz@webkit.org
no flags Details
Emit load events before notifying the WebFrame load delegate (5.93 KB, patch)
2006-03-15 16:30 PST, mitz@webkit.org
darin: review+
Review Patch | Details | Formatted Diff | Diff


Note

You need to log in before you can comment on or make changes to this bug.


Description From 2006-03-09 21:52:02 PST
Yeah, I'm not too sure about it myself yet, but I've been struggling for hours with seemingly random test case regressions that shouldn't be caused by my patch, and this bug seems to be the cause.

Basically, if you introduce a delay into DRT's code, and it doesn't like it, the RenderTree will be output before javascript requesting text only output can run, which will obviously make test cases fail. 

I've reproduced this on a clean source tree by simply loading DumpRenderTree up in a debugger, running it with LayoutTests/dom/html/level2/html/HTMLBodyElement07.html, and pausing execution at some point while it runs, and then resuming it. That causes it to consistently output the full render tree for me, even though that specific test case requests a text only output.

I won't be able to submit my patch to 5122 until this is fixed :(
------- Comment #1 From 2006-03-09 22:02:38 PST -------
In fact, it even happens when just running it in the debugger with no breakpoints or pauses. It seems pretty random
------- Comment #2 From 2006-03-09 22:14:30 PST -------
Sounds like the same as this random failure I got from BuildBot yesterday: <http://build.webkit.org/results/post-commit-powerpc-mac-os-x/990/results.html>. 
------- Comment #3 From 2006-03-09 22:46:03 PST -------
Created an attachment (id=6975) [details]
A test case for the bug

To reproduce the bug, try putting this in your WebKit folder, and type

bash Bug.bash > results

This is simultaneously running the same test 20 times to make sure it gets nice and slow, and outputting it to the results file. If you check the results when it's done, you'll find that several of the results give the full render tree of the unmodified (by the javascript onload event) page, and others show a text only representation of the modified page. 
------- Comment #4 From 2006-03-10 01:01:59 PST -------
It's apparently not specific to DumpRenderTree, but that's just where I ran into it. I'll look deeper into it tomorrow
------- Comment #5 From 2006-03-10 05:09:02 PST -------
The root cause for the undeterministic behavior is that <object> (and perhaps other) subframes are created and loaded by the render tree, triggered either by the layout timer or by event dispatch or by other mechanisms.

Frame::checkCompleted(), which emits the load DOM event, waits for the subframes to load, but obviously only if they have already been created. This warrants a bug by itself, since it means that the document load event may arbitrarily be emitted before subframes have loaded.

What's causing the problem here, though, is that in the case that the subframe gets created and its main resource fails to load, the order of calls in -[WebDataSource _receivedMainResourceError:complete:] is such that the WebFrame reports completion (which invokes DRT's waiting delegate and causes it to dump) before the WebCore Frame checks for completion (which fires the onload handler, calling dumpAsText, waitUntilDone etc. when it's too late).
------- Comment #6 From 2006-03-10 06:36:16 PST -------
Created an attachment (id=6986) [details]
Reduction

This file reliably reproduces the bug. When you invoke DRT on it, the lines appear in the reverse order, since the dump is triggered before the load event.

If you delete the <script></script> on the fifth line, the lines appear in the correct order, since the subframe loading isn't triggered.

The order of the calls in -[WebDataSource _receivedMainResourceError:complete:] was changed in r10901 to fix <rdar://problem/3853672> (Malformed HTML using crashes Safari in NSFireTimer), so part of this bug is probably a regression.
------- Comment #7 From 2006-03-15 16:30:59 PST -------
Created an attachment (id=7096) [details]
Emit load events before notifying the WebFrame load delegate

Retaining the bridge and checking the cancelled flag in -[WebLoader didFailWithError:] are sufficient to prevent the <rdar://problem/3853672> crash (or an assertion failure).

The updated acid2 results should finally fix bug 5487.

This patch obviously doesn't address the other issue I mentioned in comment #5.
------- Comment #8 From 2006-03-15 17:01:52 PST -------
I am pretty sure now (also based on the date bug 5487 was reported) that this is a regression from the fix for <rdar://problem/3853672>.
------- Comment #9 From 2006-03-15 17:08:18 PST -------
(In reply to comment #5)
> The root cause for the undeterministic behavior is that <object> (and perhaps
> other) subframes are created and loaded by the render tree, triggered either by
> the layout timer or by event dispatch or by other mechanisms.
> 
> Frame::checkCompleted(), which emits the load DOM event, waits for the
> subframes to load, but obviously only if they have already been created. This
> warrants a bug by itself, since it means that the document load event may
> arbitrarily be emitted before subframes have loaded.

Either Maciej or Hyatt (can't remember which) mentioned to me the other day that we probably should be loading subframes based on the DOM tree, not the render tree.
------- Comment #10 From 2006-03-16 01:00:22 PST -------
(From update of attachment 7096 [details])
OK. Seems like we can do this -- taking a risk sounds good. Shouldn't have braces around that return in WebLoader.m.

r=me
------- Comment #11 From 2006-03-17 12:30:19 PST -------
I comitted this patch