Also, for many urls (I randomly checked some in the middle with 12% regressions) the 'navigationStart' was sampled at the very beginning of 'TimelineBasedPageTest.RunNavigateSteps', meaning that telemetry overhead was included in TimeToFCP. (See attached pic)

I'm not sure but is that the expected behavior?

Sample Trace from CT without patch:
https://console.developers.google.com/m/cloudstorage/b/chrome-telemetry-output/o/http___www_digid_nl_2018-06-04_22-50-06_12527.html

Deleted: TtoFCP-include-DevTools.png 1016 KB

	TtoFCP-include-DevTools.png 1016 KB View Download

Deep, would you have any time to take a peek at this?

I looked at the attached trace, and it looks like we don't have the proper navigation start events in the trace. There are navStart events around 400ms, and then the next ones are around 5000ms. Either chrome is not recording those trace events (we fixed a similar problem in  Issue 809833 ), or we're stripping those events away somewhere in the telemetry code.  

I take that back. My comment was a reply to #2, and upon further inspection I think that trace is working as intended. Navigation start is supposed to be at the beginning of 'TimelineBasedPageTest.RunNavigateSteps' because that's when we navigate. It's a little confusing because the initial resource load doesn't show up among the renderer ResourceLoad async slices, and that's because the initial resource load now happens in the browser process because of PlzNavigate. 'WebContentsImpl Loading' in the browser process is properly lined up.  

Regarding redirects in the original bug, I was under the impression that HTTP redirects don't create additional navigationStart events, so this is not usually an issue. However, this is clearly not the case here. I wonder if this is a navigation initiated by javascript, in which case it would be difficult to find the root navigation for FCP in the general case. 

I can't reproduce this locally by navigating to windowsazure.com. Do you have repro steps for this? Maybe adding some additional trace events will shed some light on what is happening here. I traced windowsazure.com locally, and the only thing that stood out to me is that it is using HTTP2.

Thanks for the investigation!

Re #c5: Ah browser side PlzNavigate! That makes sense then, thanks for pointing out!

Re #c6: (Just to clarify - I don't know how 'navigationStart' was recorded, and 'redirect' mentioned in #c0 is just a random guess.)

Unfortunately I cannot reproduce windowsazure.com locally either (e.g. Downloaded the archive). The only thing I know about redirects is that 'navigation_url_loader_impl.cc' may start a new request in certain cases even if it should be a redirect (e.g. probably related to interceptor):
https://cs.chromium.org/chromium/src/content/browser/loader/navigation_url_loader_impl.cc?l=862&rcl=dfcd76263e20e52bf2d44d6ec0d57998ba49e36f


+kouhei@ ksakamoto@:
Do you have any insights on why we are seeing multiple 'navigationStart's in 'www.windowsazure.com - Traces w/o patch - trace1'?
https://ct.skia.org/results/cluster-telemetry/tasks/chromium_perf_runs/chongz-20180521181534/html/fieldname3.html

Thanks!

I could not reproduce windowsazure.com too, but this looks like the same as this bug:
https://github.com/catapult-project/catapult/issues/4490

I suspect we'll want some kind of navigation ID, which we can dump into the trace.

Does such an ID exist today?

+1 to navigation ID, I think that's probably the sanest way to link these events

We have the devtools frame token today on frames: https://cs.chromium.org/chromium/src/third_party/blink/renderer/core/frame/frame.cc?l=302&rcl=36261ec5ea1bc5461dad64d119d3edebfac0871e

Could we add a similar token on document? It looks like we have these events once per document [1]. I'm assuming there is a 1:1 mapping between a navigation start event and a document; not completely certain that's a valid assumption. 

[1]: https://www.w3.org/TR/paint-timing/#html-event-loop-processing-model

So I was able to reproduce this with a go link redirection.  I attached the trace to show that we calculate it form the wrong start.  You can also use the example in https://github.com/catapult-project/catapult/issues/4490 trace and reproduce it. 

I will investigate adding the navigation id to see if it fixes the problem.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/f80143088ca19a0af1fb3dd75e8503031ebaed25

commit f80143088ca19a0af1fb3dd75e8503031ebaed25
Author: chromium-autoroll <chromium-autoroll@skia-public.iam.gserviceaccount.com>
Date: Mon Oct 08 17:40:15 2018

Roll src/third_party/catapult 4fc4281d2152..9ec8468cfde0 (1 commits)

https://chromium.googlesource.com/catapult.git/+log/4fc4281d2152..9ec8468cfde0


git log 4fc4281d2152..9ec8468cfde0 --date=short --no-merges --format='%ad %ae %s'
2018-10-08 eyaich@google.com Implementing firstContfulPaint metric using navigationId when present.


Created with:
  gclient setdep -r src/third_party/catapult@9ec8468cfde0

The AutoRoll server is located here: https://autoroll.skia.org/r/catapult-autoroll

Documentation for the AutoRoller is here:
https://skia.googlesource.com/buildbot/+/master/autoroll/README.md

If the roll is causing failures, please contact the current sheriff, who should
be CC'd on the roll, and stop the roller if necessary.

CQ_INCLUDE_TRYBOTS=luci.chromium.try:android_optional_gpu_tests_rel;luci.chromium.try:linux_optional_gpu_tests_rel;luci.chromium.try:mac_optional_gpu_tests_rel;luci.chromium.try:win_optional_gpu_tests_rel

BUG= chromium:850258 
TBR=sullivan@chromium.org

Change-Id: I232dff89dc72296dd64dcbc55bc246f7b4a41f08
Reviewed-on: https://chromium-review.googlesource.com/c/1268695
Reviewed-by: chromium-autoroll <chromium-autoroll@skia-public.iam.gserviceaccount.com>
Commit-Queue: chromium-autoroll <chromium-autoroll@skia-public.iam.gserviceaccount.com>
Cr-Commit-Position: refs/heads/master@{#597600}
[modify] https://crrev.com/f80143088ca19a0af1fb3dd75e8503031ebaed25/DEPS

Is this finished?