Bug 46301 – [Web Timing] Implement dom* timing marks

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

[Tony Gentilcore]

Four additional timing marks have been added to the Web Timing specification:
http://dev.w3.org/2006/webapi/WebTiming/#nt-dom-loading
http://dev.w3.org/2006/webapi/WebTiming/#nt-dom-interactive
http://dev.w3.org/2006/webapi/WebTiming/#nt-dom-content-loaded
http://dev.w3.org/2006/webapi/WebTiming/#nt-dom-complete

These are also in the IE9 beta implementation. We should add these.

[James Simonsen]

Created attachment 69560 [details]
Patch

[James Simonsen]

FYI, this patch assumes that we only care about the first time the document reaches a new readiness state. The expected behavior is not clearly defined in the spec when document.open() is called. Hopefully, it'll be resolved in the web-perf meeting next Tuesday.

[Tony Gentilcore]

Comment on attachment 69560 [details]
Patch

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

Nice patch!

A few very minor comments. Again, I can't r+ this, so I'm adding abarth.

> LayoutTests/fast/dom/script-tests/webtiming-document-open.js:4
> +var originalTiming = [];

s/[]/{}/

> LayoutTests/fast/dom/script-tests/webtiming-document-open.js:21
> +    shouldBe("timing.navigationStart", "originalTiming.navigationStart");

What do you think about writing this test as a loop so that if new members are added they are automatically tested.

For example:
for (var prop in timing) {
  shouldBe("timing." + prop, "originalTiming." + prop);
}

> LayoutTests/fast/dom/script-tests/webtiming.js:41
> +    shouldBeGreaterThanOrEqual("timing.domLoading", "timing.responseStart");

Perhaps we should use fetchStart instead of responseStart. It is marked in WebKit so it will be accurate here. responseStart is reported by the platform, so I believe it is always zero in the test. Ditto for other responseStarts.

> LayoutTests/fast/dom/script-tests/webtiming.js:77
> +    shouldBeGreaterThanOrEqual("timing.domInteractive", "timing.responseEnd");

We should have a test that verifies at the time we run deferred scripts, both domLoading and domInteractive are set, but domContentLoaded and domComplete are not.

> LayoutTests/fast/dom/script-tests/webtiming.js:78
> +    shouldBeGreaterThanOrEqual("timing.domContentLoaded", "timing.domInteractive");

We should have a test that verifies that at the time a slow async script executes, domLoading, domInteractive, and domContentLoaded are all set, but domComplete is not.

> LayoutTests/fast/dom/webtiming-document-open-expected.txt:1
> +This test verifies that the NavigationTimers don't change after a document.open().

s/NavigationTimers/NavigationTimings/

> WebCore/WebCore.gypi:1178
> +            'dom/DocumentTiming.h',

Unfortunately adding a file in WebCore isn't this easy. This would break other ports.

Here's an example of a patch that modifies the build files necessary to add a new header file:
http://trac.webkit.org/changeset/64051

> WebCore/dom/DocumentTiming.h:31
> +struct DocumentTiming {

I'm not sure if this should subclass FastAllocBase. Sent an email to webkit-dev:
https://lists.webkit.org/pipermail/webkit-dev/2010-October/014603.html

> WebCore/dom/DocumentTiming.h:40
> +    double loadingOccurred;

What do you think about just using the names from the spec? eg. s/loadingOccurred/domLoading/

> WebCore/page/Timing.h:42
> +struct DocumentTiming;

struct forward declarations get alphabetized along with the classes. So this should be below DocumentLoader.

> WebCore/page/Timing.idl:51
> +        readonly attribute unsigned long long domComplete;

This should require an update to fast/dom/Window/window-properties-performance-expected.txt. You may have been running the tests on a port that skips that test.

[Adam Barth]

Comment on attachment 69560 [details]
Patch

I'll be happy to look at this once you address Tony's comments.  Thanks for the patch.

[James Simonsen]

Created attachment 69886 [details]
Patch

[James Simonsen]

(In reply to comment #3)

I addressed everything, with these additional comments...

> > LayoutTests/fast/dom/script-tests/webtiming-document-open.js:21
> > +    shouldBe("timing.navigationStart", "originalTiming.navigationStart");
> 
> What do you think about writing this test as a loop so that if new members are added they are automatically tested.
> 
> For example:
> for (var prop in timing) {
>   shouldBe("timing." + prop, "originalTiming." + prop);
> }

I wasn't sure about the order that for...in produces and how consistent that'd be over time. I see that the navigate-within-doc test has the same issue. How about sorting the keys before comparing them? That way it's easy to know what change to make to the -expected.txt files instead of trial and error.

> > LayoutTests/fast/dom/script-tests/webtiming.js:77
> > +    shouldBeGreaterThanOrEqual("timing.domInteractive", "timing.responseEnd");
> 
> We should have a test that verifies at the time we run deferred scripts, both domLoading and domInteractive are set, but domContentLoaded and domComplete are not.

Nice catch on these. This test always fails though. It looks like WebKit doesn't run the deferred scripts at the right time. They're run after the DOMContentLoaded event fires. It looks like an oversight. So, I left this test case out. Would it be better to check it in, but have it expect to fail?

[James Simonsen]

Created attachment 69991 [details]
Patch

[James Simonsen]

Sorry, the last patch was missing a file. I've updated it.

[David Levin]

The ChangeLog entries are in the middle of the files instead of the top.

[James Simonsen]

Created attachment 70028 [details]
Patch

[Tony Gentilcore]

> I wasn't sure about the order that for...in produces and how consistent that'd be over time. I see that the navigate-within-doc test has the same issue. How about sorting the keys before comparing them? That way it's easy to know what change to make to the -expected.txt files instead of trial and error.

Yep, sorting sounds like a good idea. The fast/dom/Window/window-properties-* tests do that I believe.

> Nice catch on these. This test always fails though. It looks like WebKit doesn't run the deferred scripts at the right time. They're run after the DOMContentLoaded event fires. It looks like an oversight. So, I left this test case out. Would it be better to check it in, but have it expect to fail?

Are you sure about that? These tests seem to show defer before DOMContentLoaded. Perhaps they have a bug?
http://trac.webkit.org/browser/trunk/LayoutTests/http/tests/misc/script-defer-expected.txt?rev=66670
http://trac.webkit.org/browser/trunk/LayoutTests/fast/dom/Document/readystate-expected.txt?rev=66841

I would like to get this final point figured out before landing this even if it does turn out to be a bug for a separate patch.

(In reply to comment #9)
> The ChangeLog entries are in the middle of the files instead of the top.

If that isn't happening automatically, you may need to:
$ git config merge.changelog.driver "resolve-ChangeLogs --merge-driver %O %A %B"

Details: http://trac.webkit.org/wiki/UsingGitWithWebKit

[James Simonsen]

Created attachment 70102 [details]
Patch

[James Simonsen]

(In reply to comment #11)

> > Nice catch on these. This test always fails though. It looks like WebKit doesn't run the deferred scripts at the right time. They're run after the DOMContentLoaded event fires. It looks like an oversight. So, I left this test case out. Would it be better to check it in, but have it expect to fail?
> 
> Are you sure about that? These tests seem to show defer before DOMContentLoaded. Perhaps they have a bug?
> http://trac.webkit.org/browser/trunk/LayoutTests/http/tests/misc/script-defer-expected.txt?rev=66670
> http://trac.webkit.org/browser/trunk/LayoutTests/fast/dom/Document/readystate-expected.txt?rev=66841
> 
> I would like to get this final point figured out before landing this even if it does turn out to be a bug for a separate patch.

You are correct. Thanks for walking me through the code. I've added the defer test.

[Tony Gentilcore]

Looks good to me.

The ChangeLogs still have an outdated list of files, but I'm not sure how strict we are about that.

[James Simonsen]

Created attachment 70108 [details]
Patch

[James Simonsen]

I fixed the ChangeLog.

[Tony Gentilcore]

This is ready for a reviewer to take a look.

[WebKit Commit Bot]

Comment on attachment 70108 [details]
Patch

Rejecting patch 70108 from commit-queue.

Failed to run "['./WebKitTools/Scripts/webkit-patch', '--status-host=queues.webkit.org', 'apply-attachment', '--force-clean', '--non-interactive', 70108]" exit_code: 2
Last 500 characters of output:
m/Document.cpp.rej
patching file WebCore/dom/Document.h
Hunk #2 succeeded at 1046 with fuzz 2 (offset 13 lines).
Hunk #3 FAILED at 1339.
1 out of 3 hunks FAILED -- saving rejects to file WebCore/dom/Document.h.rej
patching file WebCore/dom/DocumentTiming.h
patching file WebCore/page/Timing.cpp
patching file WebCore/page/Timing.h
patching file WebCore/page/Timing.idl

Failed to run "[u'/Projects/CommitQueue/WebKitTools/Scripts/svn-apply', u'--reviewer', u'Darin Fisher', u'--force']" exit_code: 1

Full output: http://queues.webkit.org/results/4759130

[James Simonsen]

Created attachment 72536 [details]
Patch

[James Simonsen]

Sorry, the patch was stale. I've updated it and merged in recent changes.

[WebKit Commit Bot]

Comment on attachment 72536 [details]
Patch

Rejecting patch 72536 from commit-queue.

Failed to run "['./WebKitTools/Scripts/webkit-patch', '--status-host=queues.webkit.org', 'build', '--no-clean', '--no-update', '--build-style=both']" exit_code: 2
Last 500 characters of output:
ebFrameNetworkingContext.o /Projects/CommitQueue/WebKit/mac/WebCoreSupport/WebFrameNetworkingContext.mm normal x86_64 objective-c++ com.apple.compilers.gcc.4_2
	CompileC /Projects/CommitQueue/WebKitBuild/WebKit.build/Debug/WebKit.build/Objects-normal/x86_64/WebView.o /Projects/CommitQueue/WebKit/mac/WebView/WebView.mm normal x86_64 objective-c++ com.apple.compilers.gcc.4_2
(47 failures)

Use of uninitialized value $_[0] in join or string at /System/Library/Perl/5.10.0/File/Spec/Unix.pm line 81.

Full output: http://queues.webkit.org/results/5007006

[James Simonsen]

Created attachment 72721 [details]
Patch

[WebKit Commit Bot]

Comment on attachment 72721 [details]
Patch

Rejecting patch 72721 from commit-queue.

Failed to run "['./WebKitTools/Scripts/webkit-patch', '--status-host=queues.webkit.org', '--bot-id=abarth-cq-sl', 'build-and-test', '--no-clean', '--no-update', '--test', '--non-interactive']" exit_code: 2
Last 500 characters of output:
..........................................................................................................................................................................................................................................................................
fast/dom/webtiming-document-open.html -> failed

Exiting early after 1 failures. 6929 tests run.
111.92s total testing time

6928 test cases (99%) succeeded
1 test case (<1%) had incorrect layout
2 test cases (<1%) had stderr output

Full output: http://queues.webkit.org/results/4951024

[WebKit Commit Bot]

Comment on attachment 72721 [details]
Patch

Rejecting patch 72721 from commit-queue.

Failed to run "['./WebKitTools/Scripts/webkit-patch', '--status-host=queues.webkit.org', 'build-and-test', '--no-clean', '--no-update', '--test', '--non-interactive']" exit_code: 2
Last 500 characters of output:
..........................................................................................................................................................................................................................................................................
fast/dom/webtiming-document-open.html -> failed

Exiting early after 1 failures. 6929 tests run.
130.91s total testing time

6928 test cases (99%) succeeded
1 test case (<1%) had incorrect layout
2 test cases (<1%) had stderr output

Full output: http://queues.webkit.org/results/4951026

[James Simonsen]

Created attachment 72787 [details]
Patch

[James Simonsen]

I didn't realize webtiming was disabled on Safari. I added the new webtiming test to the list of Safari skipped tests.

[WebKit Commit Bot]

Comment on attachment 72787 [details]
Patch

Rejecting patch 72787 from commit-queue.

Failed to run "['./WebKitTools/Scripts/webkit-patch', '--status-host=queues.webkit.org', '--bot-id=abarth-cq-sl', 'land-attachment', '--force-clean', '--ignore-builders', '--non-interactive', '--parent-command=commit-queue', 72787]" exit_code: 1
Last 500 characters of output:
Fetching: https://bugs.webkit.org/show_bug.cgi?id=46301&ctype=xml
Processing 1 patch from 1 bug.
Cleaning working directory
Updating working directory
Processing patch 72787 from bug 46301.
NOBODY (OOPS!) found in /Users/abarth/git/webkit-queue/LayoutTests/ChangeLog does not appear to be a valid reviewer according to committers.py.
ERROR: /Users/abarth/git/webkit-queue/LayoutTests/ChangeLog neither lists a valid reviewer nor contains the string "Unreviewed" or "Rubber stamp" (case insensitive).

Full output: http://queues.webkit.org/results/5024009

[James Simonsen]

Created attachment 72839 [details]
Patch

[WebKit Commit Bot]

Comment on attachment 72839 [details]
Patch

Clearing flags on attachment: 72839

Committed r71313: <http://trac.webkit.org/changeset/71313>

[WebKit Review Bot]

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