wylieb@ - there is a delay between first meaningful paint for the page and when we request the fetch. Just to confirm, did you wait 2+ seconds after ~page load to make sure the log didn't show up after that?

donnd@ or fgorski@ - will one of you please look into this? It seems likely to either be a bug in the metrics recorder or the FetchHelper.

Tentatively marking this as M69 since we need to make sure our metrics reporting is correct before we start our stable experiment.

I waited on the page for much longer than that, even scrolled around a bit.

I can repro this problem too, and I'd guess it has something to do with the way the EoC button does the navigation.  The forward button triggers EoC recording page-setup, but the EoC button doesn't.

All the other nagivations call contextual_suggestions_metrics_reporter->SetupForPage except for the one triggered by the EoC button.
When I hit the back button I see another SetupForPage on Frog, and hitting the forward button does SetupForPage on Toad.

Here's the full log:
08-10 11:33:26.416 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(31)] ctxs SetupForPage: https://www.google.com/search?q=frog&oq=frog&aqs=chrome..69i57j5j0l2.3704j0j7&sourceid=chrome-mobile&ie=UTF-8
08-10 11:33:26.416 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 1
08-10 11:33:28.313 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 2
08-10 11:33:28.438 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 6
08-10 11:33:47.048 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(31)] ctxs SetupForPage: https://en.m.wikipedia.org/wiki/Frog
08-10 11:33:47.048 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 1
08-10 11:33:48.890 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 2
08-10 11:33:49.043 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 7
08-10 11:33:49.053 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 15
08-10 11:33:55.315 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 9
08-10 11:33:57.647 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 12
08-10 11:34:28.657 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(31)] ctxs SetupForPage: https://en.m.wikipedia.org/wiki/Frog
08-10 11:34:28.657 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 1
08-10 11:34:30.530 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 2
08-10 11:34:30.535 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 15
08-10 11:34:38.720 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(31)] ctxs SetupForPage: https://en.m.wikipedia.org/wiki/Toad
08-10 11:34:38.720 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 1
08-10 11:34:40.661 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 2
08-10 11:34:40.847 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 7
08-10 11:34:40.848 15342 15342 I chromium: [INFO:contextual_suggestions_metrics_reporter.cc(39)] ctxs RecordEvent: 5

+pnoland for EoC navigation thoughts.

Worth mentioning that this only seems to be the case where there's no suggestions available.

> Worth mentioning that this only seems to be the case where there's no suggestions available.
Glad you mentioned this since it could be a hint for what's going wrong.  However based on the event list I think there were actually suggestions but they were all below the confidence threshold needed to show them (that's what the final 5 means in the event list from #3).

This is a problem of triggering for that page and is likely not related to the fact that the page was opened from EoC.
I was not able to get the suggestions for that page with or without EoC. Perhaps it loads to quickly and there is some race condition between this and FetchHelper.

go/eoc-debug shows that we should have suggestions here.

Filip, you may be right, but are you sure the suggestions are not just scored below the reporting threshold?  That's what I was trying to say in #6, and it looks like they all have a score below 0.5.  To me the odd behavior was no call to SetupForPage when navigating via EoC but it did get called when navigating with the forward arrow.  Just checking! 

I think we would still extend a fetch to learn that we score below threshold in that case. I don't see how we would learn that otherwise.

Looks like we have a bit of an issue with properly handling canonical URLs as well as fetch triggering in cases that tabs are quickly updated.

Update on Toad situation:
* In general, its results are suppressed or empty, probably due to bad quality
* It is no longer offered for the Frog wiki page

I am using toad on Britannica, which offers a pointer to Toad and a few others, like common toad which has suggestions.

To further elaborate on the issue:
When switching between pages using back button and EoC we can get into a state where:
URL of the page is: https://en.wikipedia.org/wiki/Common_toad
canonical URL is:   https://www.britanica.com/animal/toad  (clearly incorrect).

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

commit adc38f78cf7ef178cd2db744ba2a4e94c1b2ac81
Author: Filip Gorski <fgorski@chromium.org>
Date: Wed Aug 15 18:31:05 2018

[EoC] Fixing race condition between page load and canonical URL getting

* While investigating the problem of not reporting triggering on some
  pages, I discovered a race condition in fetching canonical URL ->
  in some cases the tab does not provide correct infromation yet.
* This patch postpones fetching of canonical URL until later, when
  we are about to perform the fetch.
* Fetching URLs would also cause some problems with marking fetch as in
  progress, which could prevent actual fetch from happening.
* It appears to also be positively affecting the EoC start time when
  loading a page for the first time.

Bug:  873004 , 841811
Change-Id: Ic7e91579d083efd54a695a10e251ec245797ba84
Reviewed-on: https://chromium-review.googlesource.com/1175108
Reviewed-by: Patrick Noland <pnoland@chromium.org>
Reviewed-by: Theresa <twellington@chromium.org>
Commit-Queue: Filip Gorski <fgorski@chromium.org>
Cr-Commit-Position: refs/heads/master@{#583334}
[modify] https://crrev.com/adc38f78cf7ef178cd2db744ba2a4e94c1b2ac81/chrome/android/java/src/org/chromium/chrome/browser/contextual_suggestions/FetchHelper.java
[modify] https://crrev.com/adc38f78cf7ef178cd2db744ba2a4e94c1b2ac81/chrome/android/junit/src/org/chromium/chrome/browser/contextual_suggestions/FetchHelperTest.java

Waiting to test in Canary (70.0.3524.0 or later) when available before requesting a merge, but that is planned for this bug.

Verified on Canary.
Things work and nothing crashes.

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

commit 8c8f402f0247883a4887705ed901d8a1fe67a451
Author: Filip Gorski <fgorski@chromium.org>
Date: Fri Aug 17 22:45:45 2018

[EoC] Fixing race condition between page load and canonical URL getting

* While investigating the problem of not reporting triggering on some
  pages, I discovered a race condition in fetching canonical URL ->
  in some cases the tab does not provide correct infromation yet.
* This patch postpones fetching of canonical URL until later, when
  we are about to perform the fetch.
* Fetching URLs would also cause some problems with marking fetch as in
  progress, which could prevent actual fetch from happening.
* It appears to also be positively affecting the EoC start time when
  loading a page for the first time.

Bug:  873004 
Change-Id: Ic7e91579d083efd54a695a10e251ec245797ba84
Reviewed-on: https://chromium-review.googlesource.com/1175108
Reviewed-by: Patrick Noland <pnoland@chromium.org>
Reviewed-by: Theresa <twellington@chromium.org>
Commit-Queue: Filip Gorski <fgorski@chromium.org>
Cr-Original-Commit-Position: refs/heads/master@{#583334}(cherry picked from commit adc38f78cf7ef178cd2db744ba2a4e94c1b2ac81)
Reviewed-on: https://chromium-review.googlesource.com/1179353
Reviewed-by: Filip Gorski <fgorski@chromium.org>
Cr-Commit-Position: refs/branch-heads/3497@{#700}
Cr-Branched-From: 271eaf50594eb818c9295dc78d364aea18c82ea8-refs/heads/master@{#576753}
[modify] https://crrev.com/8c8f402f0247883a4887705ed901d8a1fe67a451/chrome/android/java/src/org/chromium/chrome/browser/contextual_suggestions/FetchHelper.java
[modify] https://crrev.com/8c8f402f0247883a4887705ed901d8a1fe67a451/chrome/android/junit/src/org/chromium/chrome/browser/contextual_suggestions/FetchHelperTest.java

The NextAction date has arrived: 2018-08-28