Fix startup_metric racing condition: It used to wait t.WaitForDocumentReadyStateToBeComplete() befo…

1. Use window.performance.timing instead of statsCollectionController to get page loading time.
2. Fix waiting condition to avoid racing condition

BUG=467964
Committed: https://crrev.com/91e201627c7dee41d085b1829b7a60daf9b9e601
Cr-Commit-Position: refs/heads/master@{#323213}

[cylee1, 2015-03-30 18:19:18]

cylee@chromium.org changed reviewers:
+ nednguyen@google.com

[nednguyen, 2015-03-30 21:25:41]

Can you wrap the description? Also this patch seems to do too many changes
that's not related to WaitForDocumentReadyStateToBeComplete fix.

https://codereview.chromium.org/1041213003/diff/20001/tools/perf/metrics/star...
File tools/perf/metrics/startup_metric.py (left):

https://codereview.chromium.org/1041213003/diff/20001/tools/perf/metrics/star...
tools/perf/metrics/startup_metric.py:59: 
What are these change about?

https://codereview.chromium.org/1041213003/diff/20001/tools/perf/metrics/star...
File tools/perf/metrics/startup_metric.py (right):

https://codereview.chromium.org/1041213003/diff/20001/tools/perf/metrics/star...
tools/perf/metrics/startup_metric.py:50: ['request_start_ms', 'load_end_ms'])
What is this renaming about?

[cylee1, 2015-03-31 10:47:38]

There're two ways to get loading page loading time, which I don't see much
difference in our case.
one through statsCollectionController (which I believe is a documented private
API)
the other is by standard window.performance.timing API
The original code uses a combination of both approach, which I think unnecessary
(unless there's something I'm not aware of).

Minimum change would be like:
 t.WaitForJavaScriptExpression(
    "'load_duration_ms' in
json.loads(statsCollectionController.tabLoadTiming()")
However the problem is statsCollectionController doesn't seem to be always
available.
The *original* code has the checking:
        if 'load_start_ms' not in result or 'load_duration_ms' not in result:	
             raise Exception("Outdated Chrome version, "	
                 "statsCollectionController.tabLoadTiming() not present")
As a result, I probably need to check if the API is available first before I
wait for it.
So the code probably would become
if statsCollectionController is available
  wait for statsCollectionController.tabLoadTiming() has field
'load_duration_ms'
else
  wait for window.performance.timing like my new code

In the case I think the first branch is totally redundant, since there's really
no benefit to use two different API to do the same thing.
Moreover, if we plan to change it to TBM, sticking to window.performance.timing
sounds more reasonable to me.

We can think the refactoring as a two step process:
1. This CL switches from statsCollectionController to window.performance.timing
2. Use TBM to read window.performance.timing equivalent from tracing data
directly

CL Description changed.

On 2015/03/30 21:25:41, nednguyen wrote:
> Can you wrap the description? Also this patch seems to do too many changes
> that's not related to WaitForDocumentReadyStateToBeComplete fix.
> 
>
https://codereview.chromium.org/1041213003/diff/20001/tools/perf/metrics/star...
> File tools/perf/metrics/startup_metric.py (left):
> 
>
https://codereview.chromium.org/1041213003/diff/20001/tools/perf/metrics/star...
> tools/perf/metrics/startup_metric.py:59: 
> What are these change about?
> 
>
https://codereview.chromium.org/1041213003/diff/20001/tools/perf/metrics/star...
> File tools/perf/metrics/startup_metric.py (right):
> 
>
https://codereview.chromium.org/1041213003/diff/20001/tools/perf/metrics/star...
> tools/perf/metrics/startup_metric.py:50: ['request_start_ms', 'load_end_ms'])
> What is this renaming about?

[cylee1, 2015-03-31 10:52:27]

https://codereview.chromium.org/1041213003/diff/20001/tools/perf/metrics/star...
File tools/perf/metrics/startup_metric.py (left):

https://codereview.chromium.org/1041213003/diff/20001/tools/perf/metrics/star...
tools/perf/metrics/startup_metric.py:59: 
On 2015/03/30 21:25:41, nednguyen wrote:
> What are these change about?

Explained in mail.

https://codereview.chromium.org/1041213003/diff/20001/tools/perf/metrics/star...
File tools/perf/metrics/startup_metric.py (right):

https://codereview.chromium.org/1041213003/diff/20001/tools/perf/metrics/star...
tools/perf/metrics/startup_metric.py:50: ['request_start_ms', 'load_end_ms'])
On 2015/03/30 21:25:41, nednguyen wrote:
> What is this renaming about?

load_start_ms + load_duration_ms = load_end_ms
it's just window.performance.timing gives load_end_ms directly, so we don't need
to sum them up manually.

[nednguyen, 2015-04-01 01:02:13]

lgtm.
Please make sure that the "foreground_tab_load_complete" metric doesn't change
with this patch.

[cylee1, 2015-04-01 08:58:38]

On 2015/04/01 01:02:13, nednguyen wrote:
> lgtm.
> Please make sure that the "foreground_tab_load_complete" metric doesn't change
> with this patch.

Thanks!
I've already checked the difference. It's around several milliseconds so I think
that's fine (the variance of each run is far larger than that).

[cylee1, 2015-04-01 08:58:56]

The CQ bit was checked by cylee@chromium.org

[commit-bot: I haz the power, 2015-04-01 08:59:15]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1041213003/20001

[commit-bot: I haz the power, 2015-04-01 11:34:58]

Committed patchset #2 (id:20001)

[commit-bot: I haz the power, 2015-04-01 11:36:02]

Patchset 2 (id:??) landed as
https://crrev.com/91e201627c7dee41d085b1829b7a60daf9b9e601
Cr-Commit-Position: refs/heads/master@{#323213}

[dsinclair, 2015-04-01 14:04:44]

A revert of this CL (patchset #2 id:20001) has been created in
https://codereview.chromium.org/1051813002/ by dsinclair@chromium.org.

The reason for reverting is: Causing test failures on several bots. See
crbug.com/472603.