The failure is:

../../chrome/browser/prerender/prerender_browsertest.cc:1721: Failure
Expected equality of these values:
  1U
    Which is: 1
  GetLinkPrerenderCount()
    Which is: 2

Which is this line:

  NavigateToDestURL();

  // Make sure the PrerenderContents for the next url is now in the manager and
  // not pending. This relies on pending prerenders being resolved in the same
  // event loop iteration as OnPrerenderStop.
  EXPECT_TRUE(UrlIsInPrerenderManager(kHtmlFileB));
  EXPECT_EQ(1U, GetLinkPrerenderCount());

The count is 1 when the following stack happens inside of NavigateToDestURL():

#1 0x559c5a9087fc prerender::PrerenderLinkManager::RemovePrerender()
#2 0x559c5a9091c6 prerender::PrerenderLinkManager::OnPrerenderStop()
#3 0x559c5a9065a4 prerender::PrerenderHandle::OnPrerenderStop()
#4 0x559c5a902ce5 prerender::PrerenderContents::NotifyPrerenderStop()
#5 0x559c5a903a72 prerender::PrerenderContents::PrepareForUse()
#6 0x559c5a90bf7a prerender::PrerenderManager::SwapInternal()
#7 0x559c5a90b339 prerender::PrerenderManager::MaybeUsePrerenderedPage()
#8 0x559c5bacd90d Navigate()
#9 0x559c5babc0b5 Browser::OpenURLFromTab()
#10 0x559c58f230ed prerender::PrerenderBrowserTest::NavigateToURLImpl()

I am having difficulty reproducing the flake, simply sleeping the SwapOut_ACK is not seeming to be sufficient, to understand why that stack doesn't happen sometimes.

This test has been flaky before my CL according to flaky dashboard, consistent with tests made flaky by slowing SwapOut_ACK though this tests' timing dependence seems different or more complicated. It has flakes on the Windows bots from 11/7/2018 which is before my CL landed.

https://test-results.appspot.com/dashboards/flakiness_dashboard.html#tests=PrerenderBrowserTest.PrerenderInfiniteLoop

Still unable to reproduce the flake on a linux or chromeos build locally, with trying additional sleeps in various places.

However when I run it in xvfb-run, and it crashes in the gpu process, it does end up doing something similar.

Expected equality of these values:
  1U
    Which is: 1
  GetLinkPrerenderCount()
    Which is: 2

Adding too many prints makes this stop failing so this seems like it may be the race. Looking more.

Slowing the Send of PrerenderHostMsg_AddLinkRelPrerender seems to make it less racey though not sure what it's racing with.

A passing run:

[1:1:1109/145237.767014:ERROR:prerender_dispatcher.cc(160)] Send AddLinkRelPrerender
[106367:106367:1109/145237.767740:ERROR:prerender_link_manager.cc(178)] adding pre (0 exist)
[1:1:1109/145237.893399:ERROR:prerender_dispatcher.cc(160)] Send AddLinkRelPrerender
[106367:106367:1109/145237.893819:ERROR:prerender_link_manager.cc(178)] adding pre (1 exist)
[106367:106367:1109/145237.908574:ERROR:prerender_browsertest.cc(1720)] **** Before nav
[106367:106367:1109/145237.908728:ERROR:prerender_link_manager.cc(434)] remove pre (2 exist)
[106367:106367:1109/145237.944941:ERROR:prerender_browsertest.cc(1722)] **** After nav
<-- Passes expectation of only 1 prerenderer.

A failing run:

[1:1:1109/145320.481390:ERROR:prerender_dispatcher.cc(160)] Send AddLinkRelPrerender
[106799:106799:1109/145320.499749:ERROR:prerender_link_manager.cc(178)] adding pre (0 exist)
[1:1:1109/145320.584754:ERROR:prerender_dispatcher.cc(160)] Send AddLinkRelPrerender
[106799:106799:1109/145320.585239:ERROR:prerender_link_manager.cc(178)] adding pre (1 exist)
[106799:106799:1109/145320.603891:ERROR:prerender_browsertest.cc(1720)] **** Before nav
[106799:106799:1109/145320.604070:ERROR:prerender_link_manager.cc(434)] remove pre (2 exist)
#33 0x7f9b2a8669c6 [1:1:1109/145320.658941:ERROR:prerender_dispatcher.cc(160)] Send AddLinkRelPrerender
[106799:106799:1109/145320.659455:ERROR:prerender_link_manager.cc(178)] adding pre (1 exist)
[106799:106799:1109/145320.801549:ERROR:prerender_browsertest.cc(1722)] **** After nav
<-- Fails expectation of only 1 prerenderer.

It seems that some renderer wants to add a pre-renderer but it only beats the navigation completing sometimes.

Ok I figured out how to make this fail reliably! This lets that wild AddLinkRelPrerender arrive before ending the navigation step consistently.

diff --git a/chrome/browser/prerender/prerender_browsertest.cc b/chrome/browser/prerender/prerender_browsertest.cc
index c9d3947cfeb5..b9cbd10b6ba6 100644
--- a/chrome/browser/prerender/prerender_browsertest.cc
+++ b/chrome/browser/prerender/prerender_browsertest.cc
@@ -990,6 +990,10 @@ class PrerenderBrowserTest : public test_utils::PrerenderInProcessBrowserTest {
     WebContents* target_web_contents = current_browser()->OpenURL(params);
     swap_observer.Wait();
 
+    base::RunLoop r;
+    PostDelayedTask(FROM_HERE, r.QuitClosure(), base::TimeDelta::FromMilliseconds(1000));
+    r.Run();
+
     if (web_contents && expect_swap_to_succeed) {
       EXPECT_EQ(web_contents, target_web_contents);
       if (call_javascript_)

Is this something preload folks could take over at this point?

Quite a number of preload browser tests are currently disabled, it may be this problem was affecting more tests and others could be fixed and enabled?

Here's what the failure looks like with that sleep in the nav step:

[ RUN      ] PrerenderBrowserTest.PrerenderInfiniteLoop
[112348:112348:1109/150722.591866:WARNING:chrome_browser_main_chromeos.cc(546)] Running as stub user with profile dir: test-user
[112348:112348:1109/150722.704717:WARNING:easy_unlock_service_regular.cc(522)] EasyUnlockServiceRegular::IsInLegacyHostMode: DeviceSyncClient not ready. Returning false.
[112348:112348:1109/150722.733117:INFO:remote_commands_service.cc(38)] Fetching remote commands.
[112348:112348:1109/150722.733207:WARNING:remote_commands_service.cc(40)] Client is not registered.
[112348:112348:1109/150722.733248:INFO:remote_commands_invalidator.cc(32)] Initialize RemoteCommandsInvalidator.
[112348:112348:1109/150722.733279:INFO:remote_commands_invalidator.cc(57)] Starting RemoteCommandsInvalidator.
[112348:112348:1109/150722.733307:INFO:remote_commands_invalidator.cc(123)] RemoteCommandsInvalidator ReloadPolicyData.
[112348:112348:1109/150722.733334:INFO:remote_commands_invalidator.cc(167)] Unregister RemoteCommandsInvalidator.
[112348:112348:1109/150722.758497:WARNING:wallpaper_controller_client.cc(358)] Cannot get wallpaper files id in RemovePolicyWallpaper. This should never happen under normal circumstances.
[112348:112348:1109/150722.843940:WARNING:diagnosticsd_bridge.cc(90)] The diagnosticsd D-Bus service is unavailable
[112348:112348:1109/150722.884819:ERROR:gpu_interface_provider.cc(87)] Not implemented reached in virtual void content::GpuInterfaceProvider::RegisterOzoneGpuInterfaces(service_manager::BinderRegistry *)
[112348:112348:1109/150722.947881:ERROR:prerender_manager.cc(332)] No data
[112348:112366:1109/150723.442003:ERROR:test_database_manager.cc(67)] Not implemented reached in virtual bool safe_browsing::TestSafeBrowsingDatabaseManager::CheckUrlForSubresourceFilter(const GURL &, safe_browsing::SafeBrowsingDatabaseManager::Client *)
[112348:112379:1109/150723.445045:WARNING:simple_synchronous_entry.cc(1251)] Could not open platform files for entry.
[1:1:1109/150723.492392:ERROR:prerender_dispatcher.cc(161)] Send AddLinkRelPrerender
[112348:112366:1109/150723.505209:ERROR:test_database_manager.cc(60)] Not implemented reached in virtual bool safe_browsing::TestSafeBrowsingDatabaseManager::CheckResourceUrl(const GURL &, safe_browsing::SafeBrowsingDatabaseManager::Client *)
[112348:112348:1109/150723.508047:ERROR:prerender_link_manager.cc(178)] adding pre 0
[112348:112366:1109/150723.515759:ERROR:test_database_manager.cc(67)] Not implemented reached in virtual bool safe_browsing::TestSafeBrowsingDatabaseManager::CheckUrlForSubresourceFilter(const GURL &, safe_browsing::SafeBrowsingDatabaseManager::Client *)
[112348:112431:1109/150723.573126:WARNING:embedded_test_server.cc(239)] Request not handled. Returning 404: /favicon.ico
[1:1:1109/150723.599755:ERROR:prerender_dispatcher.cc(161)] Send AddLinkRelPrerender
[112348:112348:1109/150723.608342:ERROR:prerender_link_manager.cc(178)] adding pre 1
[112348:112348:1109/150723.619347:ERROR:prerender_browsertest.cc(1724)] **** Before nav

[112348:112348:1109/150723.619622:ERROR:prerender_link_manager.cc(434)] remove pre 2
[112348:112366:1109/150723.632172:ERROR:test_database_manager.cc(67)] Not implemented reached in virtual bool safe_browsing::TestSafeBrowsingDatabaseManager::CheckUrlForSubresourceFilter(const GURL &, safe_browsing::SafeBrowsingDatabaseManager::Client *)
[1:1:1109/150723.697631:ERROR:prerender_dispatcher.cc(161)] Send AddLinkRelPrerender
[112348:112348:1109/150723.697986:ERROR:prerender_link_manager.cc(178)] adding pre 1
[112348:112348:1109/150724.654804:ERROR:prerender_browsertest.cc(1726)] **** After nav
../../chrome/browser/prerender/prerender_browsertest.cc:1733: Failure
Expected equality of these values:
  1U
    Which is: 1
  GetLinkPrerenderCount()
    Which is: 2
Stack trace:
#0 0x564c8103dd7c testing::internal::UnitTestImpl::CurrentOsStackTraceExceptTop()
#1 0x564c8103d749 testing::internal::AssertHelper::operator=()
#2 0x564c7fe70674 prerender::PrerenderBrowserTest_PrerenderInfiniteLoop_Test::RunTestOnMainThread()
#3 0x564c82642a87 content::BrowserTestBase::ProxyRunTestOnMainThreadLoop()
#4 0x564c820d82f1 ChromeBrowserMainParts::PreMainMessageLoopRunImpl()
#5 0x564c820d7115 ChromeBrowserMainParts::PreMainMessageLoopRun()
#6 0x564c817d3b85 chromeos::ChromeBrowserMainPartsChromeos::PreMainMessageLoopRun()
#7 0x7f1c1eb58b4a content::BrowserMainLoop::PreMainMessageLoopRun()
#8 0x7f1c1f0527b5 content::StartupTaskRunner::RunAllTasksNow()
#9 0x7f1c1eb57671 content::BrowserMainLoop::CreateStartupTasks()
#10 0x7f1c1eb5b210 content::BrowserMainRunnerImpl::Initialize()
#11 0x7f1c1eb55222 content::BrowserMain()
#12 0x7f1c1f625c46 content::ContentMainRunnerImpl::Run()
#13 0x7f1c137e7e46 service_manager::Main()
#14 0x7f1c1f623f34 content::ContentMain()
#15 0x564c8264265c content::BrowserTestBase::SetUp()
#16 0x564c8207e26b InProcessBrowserTest::SetUp()

[112348:112348:1109/150726.841100:ERROR:prerender_link_manager.cc(434)] remove pre 2
[112348:112348:1109/150726.841175:ERROR:prerender_link_manager.cc(474)] cancel pending 1



The bonus AddLinkRelPrerender IPC comes from here:
[1:1:1109/151051.775294:ERROR:prerender_dispatcher.cc(161)] Send AddLinkRelPrerender
#0 0x7fc90db830bf base::debug::StackTrace::StackTrace()
#1 0x557595f13105 prerender::PrerenderDispatcher::Add()
#2 0x7fc901667dfa blink::Prerender::Add()
#3 0x7fc9032e80b2 blink::PrerenderHandle::Create()
#4 0x7fc9032d22de blink::LinkLoader::LoadLink()
#5 0x7fc902ec18f7 blink::HTMLLinkElement::LoadLink()
#6 0x7fc902efb876 blink::LinkStyle::Process()
#7 0x7fc902ec1e0e blink::HTMLLinkElement::InsertedInto()
#8 0x7fc902a04521 blink::ContainerNode::NotifyNodeInsertedInternal()
#9 0x7fc902a01aee blink::ContainerNode::NotifyNodeInserted()
#10 0x7fc9029fed7c blink::ContainerNode::ParserAppendChild()
#11 0x7fc903882ff9 blink::Insert()
#12 0x7fc90387ba36 blink::HTMLConstructionSite::ExecuteTask()
#13 0x7fc90387d269 blink::HTMLConstructionSite::ExecuteQueuedTasks()
#14 0x7fc9038c61c5 blink::HTMLTreeBuilder::ConstructTree()
#15 0x7fc903889c6d blink::HTMLDocumentParser::ConstructTreeFromCompactHTMLToken()
#16 0x7fc903889446 blink::HTMLDocumentParser::ProcessTokenizedChunkFromBackgroundParser()
#17 0x7fc9038878bb blink::HTMLDocumentParser::PumpPendingSpeculations()
#18 0x7fc90388737c blink::HTMLDocumentParser::ResumeParsingAfterYield()
#19 0x7fc90263f056 WTF::ThreadCheckingCallbackWrapper<>::Run()

The test loads two pages:

prerender_infinite_a.html
prerender_infinite_b.html

The first has a link to the 2nd, and vice versa.

At first it expects to have 2 "link prerenderers" going, when pre-rendering A. Then when it navigates to A, it expects to have only 1 "link prerenderer" going, for the B page linked from A.

But it seems like we do in fact get a prerenderer for A going, because there is another link prerenderer started.

So it seems to me this test is failing legitimately, and was hiding that fact by exiting too early?

As such I think pre-render folks really need to have a look.. I will reassign and disable on TOT for now to not block others on this test's failing/timing issues.

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

commit 0669d9a05ffe58c2a50c3f490c6386aaedf19fd2
Author: danakj <danakj@chromium.org>
Date: Fri Nov 09 21:41:48 2018

Disable flaky PrerenderBrowserTest.PrerenderInfiniteLoop.

During the navigation in the test, a renderer is loading a page and
if it completes in time, sends a AddLinkRelPrerender IPC to the browser
to start a link prerenderer.

If this occurs before the navigation started by the test completes, then
the test will fail with the wrong number of prerenderers.

This seems to imply the test is exiting too quickly, and not observing
the actual number of prerenderers that we create.

TBR=droger@chromium.org
NOTRY=true

Change-Id: If74bf60f45b60f52041167532eca9915c6d604b3
Bug:  903695 
Reviewed-on: https://chromium-review.googlesource.com/c/1330287
Reviewed-by: danakj <danakj@chromium.org>
Commit-Queue: danakj <danakj@chromium.org>
Cr-Commit-Position: refs/heads/master@{#606975}
[modify] https://crrev.com/0669d9a05ffe58c2a50c3f490c6386aaedf19fd2/chrome/browser/prerender/prerender_browsertest.cc

Thanks Dana. You may be right, we'll take a look.

(re-assigning from droger@ as he's on a different project now)

AFAICT the test checks that link-rel prerenders are held in the pending state if the page requesting them is a prerender itself.

Initially I wanted to just remove this test because of its use of FINAL_STATUS_USED (which, ironically, is never used now). I always assumed that nostate-prefetch won't ping PrerenderLinkManager before suicide. And now I realize that this assumption is something that we probably need to test for in prerender_nostate_prefetch_browsertest.cc. I think we do not have a test like this yet.

mattcary: does this sound reasonable?

P1 -> P2 because spawning prerenders from prerendered page should be unreachable in recent versions.

Yes, I agree, that's what I wanted to run by you today. SGTM, I'll start that.

Thanks.

> (re-assigning from droger@ as he's on a different project now)

FYI: https://cs.chromium.org/chromium/src/chrome/browser/prerender/OWNERS?rcl=b3bf64e2aa498d39ee246c7183dd7c1f17f5f3f6&l=1

Oops, thanks, I'll update the owners file :)

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

commit 276256f3b00276cb91fe25a518e1b62021c79d04
Author: Matthew Cary <mattcary@chromium.org>
Date: Wed Nov 14 10:15:03 2018

Prerender: test no recursive NoStatePrefetch.

Obsolete and flaky tests for the disabled classical prerender are
removed.

This test also adds an ignored ExpectedContents to prevent a race
condition in the test when a PrerenderContents final status may be
checked before or after the test tears itself down.

Bug:  903695 
Change-Id: Ia77b3beb79bf579ca1904c54e469f0de4b648f94
Reviewed-on: https://chromium-review.googlesource.com/c/1333779
Commit-Queue: Matthew Cary <mattcary@chromium.org>
Reviewed-by: Egor Pasko <pasko@chromium.org>
Cr-Commit-Position: refs/heads/master@{#607944}
[modify] https://crrev.com/276256f3b00276cb91fe25a518e1b62021c79d04/chrome/browser/prerender/prerender_browsertest.cc
[modify] https://crrev.com/276256f3b00276cb91fe25a518e1b62021c79d04/chrome/browser/prerender/prerender_nostate_prefetch_browsertest.cc
[modify] https://crrev.com/276256f3b00276cb91fe25a518e1b62021c79d04/chrome/browser/prerender/prerender_test_utils.cc
[modify] https://crrev.com/276256f3b00276cb91fe25a518e1b62021c79d04/chrome/browser/prerender/prerender_test_utils.h
[add] https://crrev.com/276256f3b00276cb91fe25a518e1b62021c79d04/chrome/test/data/prerender/prefetch_nostore_page.html
[add] https://crrev.com/276256f3b00276cb91fe25a518e1b62021c79d04/chrome/test/data/prerender/prefetch_nostore_page.html.mock-http-headers
[add] https://crrev.com/276256f3b00276cb91fe25a518e1b62021c79d04/chrome/test/data/prerender/prefetch_recurse.html
[delete] https://crrev.com/678fc40f10bb52e86d53f9f49ce936ecf98162b0/chrome/test/data/prerender/prerender_infinite_a_multiple.html
[delete] https://crrev.com/678fc40f10bb52e86d53f9f49ce936ecf98162b0/chrome/test/data/prerender/prerender_infinite_b_multiple.html
[delete] https://crrev.com/678fc40f10bb52e86d53f9f49ce936ecf98162b0/chrome/test/data/prerender/prerender_infinite_c_multiple.html