New issue
Advanced search Search tips

Issue 842925 link

Starred by 5 users

Issue metadata

Status: Fixed
Owner:
Closed: May 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 1
Type: Bug



Sign in to add a comment

Flaky CHECK(IsJavascriptAllowed()) during browser_tests on win10_chromium_x64_rel_ng CQ bot

Project Member Reported by ynovikov@chromium.org, May 14 2018

Issue description

Happened to me in https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5833 on an unrelated CL.

[ RUN      ] MSE_ClearKey/EncryptedMediaTest.Playback_Multiple_VideoAudio_WebM/0
[7512:7440:0514/125909.255:FATAL:web_ui_message_handler.h(122)] Check failed: IsJavascriptAllowed(). Cannot CallJavascriptFunction before explicitly allowing JavaScript.
Backtrace:
	base::debug::StackTrace::StackTrace [0x00007FF68C043764+36]
	logging::LogMessage::~LogMessage [0x00007FF68C060092+98]
	content::WebUIMessageHandler::CallJavascriptFunction<base::Value,base::Value,base::Value> [0x00007FF68AF882E1+137]
	content::WebUIMessageHandler::ResolveJavascriptCallback [0x00007FF68AF8822A+124]
	WelcomeWin10Handler::SendPinnedToTaskbarStateResult [0x00007FF68EBAF644+130]
	WelcomeWin10Handler::OnIsPinnedToTaskbarDetermined [0x00007FF68EBAF79D+301]
	base::Timer::RunScheduledTask [0x00007FF68C0B6896+246]
	base::debug::TaskAnnotator::RunTask [0x00007FF68C04413E+382]
	base::internal::IncomingTaskQueue::RunTask [0x00007FF68D22D49E+126]
	base::MessageLoop::RunTask [0x00007FF68C06C2D9+665]
	base::MessageLoop::DeferOrRunPendingTask [0x00007FF68C06C717+183]
	base::MessageLoop::DoDelayedWork [0x00007FF68C06CC1E+622]
	base::MessagePumpForUI::DoRunLoop [0x00007FF68C06E9A2+194]
	base::MessagePumpWin::Run [0x00007FF68C06E428+104]
	base::MessageLoop::Run [0x00007FF68C06BCCB+139]
	base::RunLoop::Run [0x00007FF68C095889+249]
	content::RunThisRunLoop [0x00007FF68C174FE4+45]
	content::MessageLoopRunner::Run [0x00007FF68C175930+122]
	ui_test_utils::NavigateToURLWithDispositionBlockUntilNavigationsComplete [0x00007FF68C118BEF+841]
	ui_test_utils::NavigateToURL [0x00007FF68C118880+29]
	MediaBrowserTest::RunTest [0x00007FF6892F7CB1+373]
	MediaBrowserTest::RunMediaTestPage [0x00007FF6892F7A2A+798]
	EncryptedMediaTestBase::RunEncryptedMediaTestPage [0x00007FF6892E34C2+76]
	EncryptedMediaTestBase::RunEncryptedMediaTest [0x00007FF6892DF679+295]
	EncryptedMediaTest::TestMultiplePlayback [0x00007FF6892DE017+287]
	EncryptedMediaTest_Playback_Multiple_VideoAudio_WebM_Test::RunTestOnMainThread [0x00007FF6892DDE7A+154]
	content::BrowserTestBase::ProxyRunTestOnMainThreadLoop [0x00007FF68C1588FF+517]
	ChromeBrowserMainParts::PreMainMessageLoopRunImpl [0x00007FF68E71C25F+4843]
	ChromeBrowserMainParts::PreMainMessageLoopRun [0x00007FF68E71AE6F+185]
	content::BrowserMainLoop::PreMainMessageLoopRun [0x00007FF68AB6EDC5+85]
	content::StartupTaskRunner::RunAllTasksNow [0x00007FF68AF2A68D+37]
	content::BrowserMainLoop::CreateStartupTasks [0x00007FF68AB6D9A7+841]
	content::BrowserMainRunnerImpl::Initialize [0x00007FF68AB71277+129]
	content::BrowserMain [0x00007FF68AB6B641+201]
	content::RunBrowserProcessMain [0x00007FF68BFFAE56+210]
	content::ContentMainRunnerImpl::Run [0x00007FF68BFFB9BB+493]
	service_manager::Main [0x00007FF68C76D2D7+1763]
	content::ContentMain [0x00007FF68BFFAD29+65]
	content::BrowserTestBase::SetUp [0x00007FF68C1585EC+2136]
	InProcessBrowserTest::SetUp [0x00007FF68C116415+533]
	testing::Test::Run [0x00007FF689FB999E+112]
	testing::TestInfo::Run [0x00007FF689FBA2E4+222]
	testing::TestCase::Run [0x00007FF689FBA78E+258]
	testing::internal::UnitTestImpl::RunAllTests [0x00007FF689FC16BA+638]
	testing::UnitTest::Run [0x00007FF689FC1395+165]
	base::TestSuite::Run [0x00007FF68C1289EA+118]
	ChromeTestSuiteRunner::RunTestSuite [0x00007FF6906C02CE+48]
	content::LaunchTests [0x00007FF68C172062+486]
	LaunchChromeTests [0x00007FF6906C0761+318]
	main [0x00007FF6906C025C+132]
	__scrt_common_main_seh [0x00007FF6906E60E1+285] (f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl:283)
	BaseThreadInitThunk [0x00007FF8FE9A2774+20]
	RtlUserThreadStart [0x00007FF901100D51+33]

[ RUN      ] CDM_9/ECKEncryptedMediaTest.MessageTypeTest/0
[6716:720:0514/125916.264:FATAL:web_ui_message_handler.h(122)] Check failed: IsJavascriptAllowed(). Cannot CallJavascriptFunction before explicitly allowing JavaScript.
Backtrace:
	base::debug::StackTrace::StackTrace [0x00007FF68C043764+36]
	logging::LogMessage::~LogMessage [0x00007FF68C060092+98]
	content::WebUIMessageHandler::CallJavascriptFunction<base::Value,base::Value,base::Value> [0x00007FF68AF882E1+137]
	content::WebUIMessageHandler::ResolveJavascriptCallback [0x00007FF68AF8822A+124]
	WelcomeWin10Handler::SendPinnedToTaskbarStateResult [0x00007FF68EBAF644+130]
	WelcomeWin10Handler::OnIsPinnedToTaskbarDetermined [0x00007FF68EBAF79D+301]
	base::Timer::RunScheduledTask [0x00007FF68C0B6896+246]
	base::debug::TaskAnnotator::RunTask [0x00007FF68C04413E+382]
	base::internal::IncomingTaskQueue::RunTask [0x00007FF68D22D49E+126]
	base::MessageLoop::RunTask [0x00007FF68C06C2D9+665]
	base::MessageLoop::DeferOrRunPendingTask [0x00007FF68C06C717+183]
	base::MessageLoop::DoDelayedWork [0x00007FF68C06CC1E+622]
	base::MessagePumpForUI::DoRunLoop [0x00007FF68C06E9A2+194]
	base::MessagePumpWin::Run [0x00007FF68C06E428+104]
	base::MessageLoop::Run [0x00007FF68C06BCCB+139]
	base::RunLoop::Run [0x00007FF68C095889+249]
	content::RunThisRunLoop [0x00007FF68C174FE4+45]
	content::MessageLoopRunner::Run [0x00007FF68C175930+122]
	ui_test_utils::NavigateToURLWithDispositionBlockUntilNavigationsComplete [0x00007FF68C118BEF+841]
	ui_test_utils::NavigateToURL [0x00007FF68C118880+29]
	MediaBrowserTest::RunTest [0x00007FF6892F7CB1+373]
	MediaBrowserTest::RunMediaTestPage [0x00007FF6892F7A2A+798]
	EncryptedMediaTestBase::RunEncryptedMediaTestPage [0x00007FF6892E34C2+76]
	EncryptedMediaTestBase::RunEncryptedMediaTest [0x00007FF6892DF679+295]
	ECKEncryptedMediaTest::TestPlaybackCase [0x00007FF6892E0748+232]
	ECKEncryptedMediaTest_MessageTypeTest_Test::RunTestOnMainThread [0x00007FF6892E0438+190]
	content::BrowserTestBase::ProxyRunTestOnMainThreadLoop [0x00007FF68C1588FF+517]
	ChromeBrowserMainParts::PreMainMessageLoopRunImpl [0x00007FF68E71C25F+4843]
	ChromeBrowserMainParts::PreMainMessageLoopRun [0x00007FF68E71AE6F+185]
	content::BrowserMainLoop::PreMainMessageLoopRun [0x00007FF68AB6EDC5+85]
	content::StartupTaskRunner::RunAllTasksNow [0x00007FF68AF2A68D+37]
	content::BrowserMainLoop::CreateStartupTasks [0x00007FF68AB6D9A7+841]
	content::BrowserMainRunnerImpl::Initialize [0x00007FF68AB71277+129]
	content::BrowserMain [0x00007FF68AB6B641+201]
	content::RunBrowserProcessMain [0x00007FF68BFFAE56+210]
	content::ContentMainRunnerImpl::Run [0x00007FF68BFFB9BB+493]
	service_manager::Main [0x00007FF68C76D2D7+1763]
	content::ContentMain [0x00007FF68BFFAD29+65]
	content::BrowserTestBase::SetUp [0x00007FF68C1585EC+2136]
	InProcessBrowserTest::SetUp [0x00007FF68C116415+533]
	testing::Test::Run [0x00007FF689FB999E+112]
	testing::TestInfo::Run [0x00007FF689FBA2E4+222]
	testing::TestCase::Run [0x00007FF689FBA78E+258]
	testing::internal::UnitTestImpl::RunAllTests [0x00007FF689FC16BA+638]
	testing::UnitTest::Run [0x00007FF689FC1395+165]
	base::TestSuite::Run [0x00007FF68C1289EA+118]
	ChromeTestSuiteRunner::RunTestSuite [0x00007FF6906C02CE+48]
	content::LaunchTests [0x00007FF68C172062+486]
	LaunchChromeTests [0x00007FF6906C0761+318]
	main [0x00007FF6906C025C+132]
	__scrt_common_main_seh [0x00007FF6906E60E1+285] (f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl:283)
	BaseThreadInitThunk [0x00007FF8FE9A2774+20]
	RtlUserThreadStart [0x00007FF901100D51+33]

Also observed this in
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/6026
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/6000
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5995
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5993
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5987
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5986
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5982
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5981
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5979
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5962
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5958 - here you can observe the flakiness, as it passed in a second run
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5954
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5953
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5949
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5948
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5945
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5939
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5935
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5922
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5920
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5915
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5908
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5886
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5885
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5883
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5882
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5870
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5864
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5862
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5861
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5860
https://ci.chromium.org/p/chromium/builders/luci.chromium.try/win10_chromium_x64_rel_ng/5859

I suspect https://chromium-review.googlesource.com/976392 based on the callstack and last CLs in classes appearing in it.
 
Cc: a...@chromium.org
Owner: ----
Actually, all the tests passed in that CL, so must be something more recent.
Cc: lukasza@chromium.org rbpotter@chromium.org
Components: Internals>Media>Encrypted Blink>Media UI>Browser>WebUI Internals>Sandbox>SiteIsolation
I have traced this as far as https://ci.chromium.org/buildbot/tryserver.chromium.win/win10_chromium_x64_rel_ng/126153 from https://chromium-review.googlesource.com/981019 failing in https://chromium-swarm.appspot.com/task?id=3cef748005a37110&refresh=10&show_raw=1.
Maybe site-per-process is related somehow? Maybe it could also explain why this fails on CQ but not on CI.
Could be also related to issue 827056.

Comment 3 by a...@chromium.org, May 15 2018

Cc: pmonette@chromium.org
I'm looking at the stack trace. This is a media test; what in the world is WelcomeWin10Handler doing in the trace? If it's randomly showing up and trying to execute JavaScript when it shouldn't, that might explain the flakiness.

+pmonette

Comment 4 by a...@chromium.org, May 15 2018

Also, if this is only happening on the Win10 bots, then the WelcomeWin10Handler showing up is awfully suspicious :(
Owner: pmonette@chromium.org
Status: Started (was: Untriaged)
I have no idea why the page is showing in a media test, but the flake is quite straightforward to fix.

I've have a CL up for review here:
https://chromium-review.googlesource.com/c/chromium/src/+/1058929
 Issue 843070  has been merged into this issue.
 Issue 843049  has been merged into this issue.
 Issue 842998  has been merged into this issue.
Project Member

Comment 9 by bugdroid1@chromium.org, May 15 2018

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

commit da9de849b64898dca7bf38c236573523615e2def
Author: Patrick Monette <pmonette@chromium.org>
Date: Tue May 15 21:50:02 2018

Clear the callback ID when refreshing chrome://welcome-win10

This is to avoid the possible race when the page is
refreshed (so the callback id is now invalid) and the result
of GetIsPinnedToTaskbarState() from the previous javascript
call is received before the current page calls
getPinnedToTaskbarState().

Bug:  842925 
Change-Id: I41e8cd3a40d22f98f020eb7bd02487713a62df98
Reviewed-on: https://chromium-review.googlesource.com/1058929
Reviewed-by: Tommy Li <tommycli@chromium.org>
Reviewed-by: Demetrios Papadopoulos <dpapad@chromium.org>
Commit-Queue: Patrick Monette <pmonette@chromium.org>
Cr-Commit-Position: refs/heads/master@{#558845}
[modify] https://crrev.com/da9de849b64898dca7bf38c236573523615e2def/chrome/browser/ui/webui/welcome_win10_handler.cc
[modify] https://crrev.com/da9de849b64898dca7bf38c236573523615e2def/chrome/browser/ui/webui/welcome_win10_handler.h

 Issue 843383  has been merged into this issue.
 Issue 843439  has been merged into this issue.
 Issue 843422  has been merged into this issue.
Status: Fixed (was: Started)

Sign in to add a comment