LoginUtilsTest.MashLogin appears to be timing out (e.g. https://ci.chromium.org/p/chromium/builders/luci.chromium.ci/linux-chromeos-dbg/9175).

Stack trace shows that `session_started_observer.Wait()` probably timed out from waiting. There are lot of ERRORs in that log, so I can't tell which one is actually causing the session to fail, if any...

Can't see anything suspicious on the blame list though.

Stack:

BrowserTestBase received signal: Terminated. Backtrace:
#0 0x7f158565b6dd base::debug::StackTrace::StackTrace()
#1 0x7f158535765a base::debug::StackTrace::StackTrace()
#2 0x5647aa460032 content::(anonymous namespace)::DumpStackTraceSignalHandler()
#3 0x7f1552562cb0 <unknown>
#4 0x7f157ff46d10 <unknown>
#5 0x7f1579e1b7e5 mojo::Binding<>::Close()
#6 0x7f157ba0b85b content::RenderFrameMetadataProviderImpl::Bind()
#7 0x7f157ba9b5c9 content::RenderWidgetHostImpl::RegisterRenderFrameMetadataObserver()
#8 0x7f157b89c281 content::FrameSinkProviderImpl::RegisterRenderFrameMetadataObserver()
#9 0x7f1579f03aaa content::mojom::FrameSinkProviderStubDispatch::Accept()
#10 0x7f157b89c443 content::mojom::FrameSinkProviderStub<>::Accept()
#11 0x7f157ff5afdd mojo::InterfaceEndpointClient::HandleValidatedMessage()
#12 0x7f157ff59a71 mojo::InterfaceEndpointClient::HandleIncomingMessageThunk::Accept()
#13 0x7f157ff57f38 mojo::FilterChain::Accept()
#14 0x7f157ff5d976 mojo::InterfaceEndpointClient::HandleIncomingMessage()
#15 0x7f157ff6a3c2 mojo::internal::MultiplexRouter::ProcessIncomingMessage()
#16 0x7f157ff699e5 mojo::internal::MultiplexRouter::Accept()
#17 0x7f157ff57f38 mojo::FilterChain::Accept()
#18 0x7f157ff4a594 mojo::Connector::ReadSingleMessage()
#19 0x7f157ff4b53a mojo::Connector::ReadAllAvailableMessages()
#20 0x7f157ff4b308 mojo::Connector::OnHandleReadyInternal()
#21 0x7f157ff4b20b mojo::Connector::OnWatcherHandleReady()
#22 0x7f157ff4ed9f _ZN4base8internal13FunctorTraitsIMN4mojo9ConnectorEFvjEvE6InvokeIS5_PS3_JjEEEvT_OT0_DpOT1_
#23 0x7f157ff4eccf _ZN4base8internal12InvokeHelperILb0EvE8MakeItSoIRKMN4mojo9ConnectorEFvjEJPS5_jEEEvOT_DpOT0_
#24 0x7f157ff4ec65 _ZN4base8internal7InvokerINS0_9BindStateIMN4mojo9ConnectorEFvjEJNS0_17UnretainedWrapperIS4_EEEEEFvjEE7RunImplIRKS6_RKNSt3__15tupleIJS8_EEEJLm0EEEEvOT_OT0_NSF_16integer_sequenceImJXspT1_EEEEOj
#25 0x7f157ff4eb8b _ZN4base8internal7InvokerINS0_9BindStateIMN4mojo9ConnectorEFvjEJNS0_17UnretainedWrapperIS4_EEEEEFvjEE3RunEPNS0_13BindStateBaseEj
#26 0x7f157ff45b7e _ZNKR4base17RepeatingCallbackIFvjEE3RunEj
#27 0x7f157ff4dccf mojo::SimpleWatcher::DiscardReadyState()
#28 0x7f157ff4df3f _ZN4base8internal13FunctorTraitsIPFvRKNS_17RepeatingCallbackIFvjEEEjRKN4mojo18HandleSignalsStateEEvE6InvokeIRKSC_JS6_jSA_EEEvOT_DpOT0_
#29 0x7f157ff4dedd _ZN4base8internal12InvokeHelperILb0EvE8MakeItSoIRKPFvRKNS_17RepeatingCallbackIFvjEEEjRKN4mojo18HandleSignalsStateEEJS8_jSC_EEEvOT_DpOT0_
#30 0x7f157ff4de80 _ZN4base8internal7InvokerINS0_9BindStateIPFvRKNS_17RepeatingCallbackIFvjEEEjRKN4mojo18HandleSignalsStateEEJS5_EEEFvjSB_EE7RunImplIRKSD_RKNSt3__15tupleIJS5_EEEJLm0EEEEvOT_OT0_NSK_16integer_sequenceImJXspT1_EEEEOjSB_
#31 0x7f157ff4dda6 _ZN4base8internal7InvokerINS0_9BindStateIPFvRKNS_17RepeatingCallbackIFvjEEEjRKN4mojo18HandleSignalsStateEEJS5_EEEFvjSB_EE3RunEPNS0_13BindStateBaseEjSB_
#32 0x7f158596237e _ZNKR4base17RepeatingCallbackIFvjRKN4mojo18HandleSignalsStateEEE3RunEjS4_
#33 0x7f1585961d1b mojo::SimpleWatcher::OnHandleReady()
#34 0x7f1585962b33 _ZN4base8internal13FunctorTraitsIMN4mojo13SimpleWatcherEFvijRKNS2_18HandleSignalsStateEEvE6InvokeIS8_RKNS_7WeakPtrIS3_EEJRKiRKjS6_EEEvT_OT0_DpOT1_
#35 0x7f1585962a75 _ZN4base8internal12InvokeHelperILb1EvE8MakeItSoIRKMN4mojo13SimpleWatcherEFvijRKNS4_18HandleSignalsStateEERKNS_7WeakPtrIS5_EEJRKiRKjS8_EEEvOT_OT0_DpOT1_
#36 0x7f15859629d2 _ZN4base8internal7InvokerINS0_9BindStateIMN4mojo13SimpleWatcherEFvijRKNS3_18HandleSignalsStateEEJNS_7WeakPtrIS4_EEijS5_EEEFvvEE7RunImplIRKS9_RKNSt3__15tupleIJSB_ijS5_EEEJLm0ELm1ELm2ELm3EEEEvOT_OT0_NSI_16integer_sequenceImJXspT1_EEEE
#37 0x7f158596281c _ZN4base8internal7InvokerINS0_9BindStateIMN4mojo13SimpleWatcherEFvijRKNS3_18HandleSignalsStateEEJNS_7WeakPtrIS4_EEijS5_EEEFvvEE3RunEPNS0_13BindStateBaseE
#38 0x7f158530927e _ZNO4base12OnceCallbackIFvvEE3RunEv
#39 0x7f1585358b0a base::debug::TaskAnnotator::RunTask()
#40 0x7f15853e9b4c base::MessageLoopImpl::RunTask()
#41 0x7f15853e9e4b base::MessageLoopImpl::DeferOrRunPendingTask()
#42 0x7f15853ea684 base::MessageLoopImpl::DoWork()
#43 0x7f15856ae819 base::MessagePumpLibevent::Run()
#44 0x7f15853e9366 base::MessageLoopImpl::Run()
#45 0x7f15854950b2 base::RunLoop::Run()
#46 0x5647aa4fb7d7 content::WindowedNotificationObserver::Wait()
#47 0x5647a3d33a88 chromeos::LoginUtilsTest::Login()
#48 0x5647a3d3380c chromeos::LoginUtilsTest_MashLogin_Test::RunTestOnMainThread()
#49 0x5647aa45e565 content::BrowserTestBase::ProxyRunTestOnMainThreadLoop()
#50 0x5647a1a09f4d _ZN4base8internal13FunctorTraitsIM25RenderViewContextMenuBaseFvvEvE6InvokeIS4_P21RenderViewContextMenuJEEEvT_OT0_DpOT1_
#51 0x5647a1a09e94 _ZN4base8internal12InvokeHelperILb0EvE8MakeItSoIM25RenderViewContextMenuBaseFvvEJP21RenderViewContextMenuEEEvOT_DpOT0_
#52 0x5647aa4613c5 _ZN4base8internal7InvokerINS0_9BindStateIMN7content15BrowserTestBaseEFvvEJNS0_17UnretainedWrapperIS4_EEEEEFvvEE7RunImplIRKS6_RKNSt3__15tupleIJS8_EEEJLm0EEEEvOT_OT0_NSF_16integer_sequenceImJXspT1_EEEE
#53 0x5647aa4612fc _ZN4base8internal7InvokerINS0_9BindStateIMN7content15BrowserTestBaseEFvvEJNS0_17UnretainedWrapperIS4_EEEEEFvvEE3RunEPNS0_13BindStateBaseE
#54 0x5647a19fa6ad _ZNKR4base17RepeatingCallbackIFvvEE3RunEv
#55 0x5647a91a31c0 ChromeBrowserMainParts::PreMainMessageLoopRunImpl()
#56 0x5647a91a12f4 ChromeBrowserMainParts::PreMainMessageLoopRun()
#57 0x5647a4928b9b chromeos::ChromeBrowserMainPartsChromeos::PreMainMessageLoopRun()
#58 0x7f157ada9da2 content::BrowserMainLoop::PreMainMessageLoopRun()
#59 0x7f15798feadd _ZN4base8internal13FunctorTraitsIMN7content12ChildProcessEFvvEvE6InvokeIS5_PS3_JEEEvT_OT0_DpOT1_
#60 0x7f15798fea24 _ZN4base8internal12InvokeHelperILb0EvE8MakeItSoIMN7content12ChildProcessEFvvEJPS5_EEEvOT_DpOT0_
#61 0x7f157adaf865 _ZN4base8internal7InvokerINS0_9BindStateIMN7content15BrowserMainLoopEFivEJNS0_17UnretainedWrapperIS4_EEEEEFivEE7RunImplIRKS6_RKNSt3__15tupleIJS8_EEEJLm0EEEEiOT_OT0_NSF_16integer_sequenceImJXspT1_EEEE
#62 0x7f157adaf79c _ZN4base8internal7InvokerINS0_9BindStateIMN7content15BrowserMainLoopEFivEJNS0_17UnretainedWrapperIS4_EEEEEFivEE3RunEPNS0_13BindStateBaseE
#63 0x7f1579800c6d _ZNKR4base17RepeatingCallbackIFvvEE3RunEv
#64 0x7f157bdaf6dd content::StartupTaskRunner::RunAllTasksNow()
#65 0x7f157ada5aff content::BrowserMainLoop::CreateStartupTasks()
#66 0x7f157adb1ee3 content::BrowserMainRunnerImpl::Initialize()
#67 0x7f157ad9d409 content::BrowserMain()
#68 0x7f157d0e7330 content::RunBrowserProcessMain()
#69 0x7f157d0e9ed6 content::ContentMainRunnerImpl::Run()
#70 0x7f157d0e014c content::ContentServiceManagerMainDelegate::RunEmbedderProcess()
#71 0x7f1550c27a61 service_manager::Main()
#72 0x7f157d0e4a65 content::ContentMain()
#73 0x5647aa45db12 content::BrowserTestBase::SetUp()
#74 0x5647a903b87b InProcessBrowserTest::SetUp()
#75 0x5647a8f5962c extensions::ExtensionBrowserTest::SetUp()
#76 0x5647a3dc5343 chromeos::OobeBaseTest::SetUp()
#77 0x5647a1a5bf3e _ZN7testing8internal12InvokeHelperIRKNSt3__16vectorIPN12user_manager4UserENS2_9allocatorIS6_EEEENS2_5tupleIJEEEE12InvokeMethodIN8chromeos15MockUserManagerEMSH_KFSB_vEEESB_PT_T0_RKSD_
#78 0x5647a583d5e2 testing::internal::HandleExceptionsInMethodIfSupported<>()
#79 0x5647a581d344 testing::Test::Run()
#80 0x5647a581dff2 testing::TestInfo::Run()
#81 0x5647a581ef0f testing::TestCase::Run()
#82 0x5647a5832dbb testing::internal::UnitTestImpl::RunAllTests()
#83 0x5647a5846eee testing::internal::HandleSehExceptionsInMethodIfSupported<>()
#84 0x5647a583ed52 testing::internal::HandleExceptionsInMethodIfSupported<>()
#85 0x5647a58329f7 testing::UnitTest::Run()
#86 0x5647a9085201 RUN_ALL_TESTS()
#87 0x5647a90823cb base::TestSuite::Run()
#88 0x5647a8f2bf37 ChromeTestSuiteRunner::RunTestSuite()
#89 0x5647a8f2c023 ChromeTestLauncherDelegate::RunTestSuite()
#90 0x5647aa4e89f9 content::LaunchTests()
#91 0x5647a8f2d372 LaunchChromeTests()
#92 0x5647a8f2b87b main
#93 0x7f155254df45 __libc_start_main
#94 0x5647a1983bea _start

I can reproduce this locally. AFAICT ash has not crashed.

When this succeeded, I saw:

[119688:119688:1126/161806.787496:INFO:CONSOLE(9946)] "Finished loading asset bundle oauth-enrollment", source: chrome://oobe/oobe.js (9946)
[119688:119688:1126/161806.798851:WARNING:CONSOLE(287)] "<webview>: The load has aborted with error -102: ERR_CONNECTION_REFUSED.", source: extensions::webViewEven\
ts (287)

logged to the console. That is not present in the failing case.

I was able to reproduce this with a Debug build on ToT, but not on my ToT
build from this morning:
BAD @ #610979
GOOD @ #610873

I'll start a bisect.

I suspect a renderer is crashing, or a pipe is getting closed. We kept ending up in RenderWidgetHostImpl::RegisterRenderFrameMetadataObserver().

I thinking this is the result of Dana's patch at  https://chromium-review.googlesource.com/c/1341073 . Will verify that shortly.

Bad @ 610923, I'll test https://chromium-review.googlesource.com/c/1341073
now.

It was in fact Dana's patch. I've reverted it and the test seems happy locally.

I repro'd locally with the following args:

--gtest_filter=LoginUtilsTest.MashLogin --enable-features=Mash--override-use-software-gl-for-tests --no-sandbox


The --no-sandbox is likely not necessary.

Seems to still be failing on MSan builder: https://ci.chromium.org/p/chromium/builders/luci.chromium.ci/Linux%20ChromiumOS%20MSan%20Tests

Filed bug at https://bugs.chromium.org/p/chromium/issues/detail?id=908724

The run with the revert is green:)

The last run on both bots are green :)

Hrm, I ran the test to make sure it passed. :|

It passes for me, most of the time. But I see that it ends up spamming the task queue really hard trying to make a frame sink until OnEmbed happens. When it does fail it seems that OnEmbed just never occurs.

It also passes more reliably in release, so I guess theres some race where OnEmbed has to happen fast enough or it just doesnt?

https://chromium-review.googlesource.com/c/chromium/src/+/1351938 relanding without changing mash so this shouldn't reoccur.