New issue
Advanced search Search tips

Issue 877218 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Closed: Aug 28
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Linux
Pri: 3
Type: Bug



Sign in to add a comment

ServiceWorkerTest.ServiceWorkerSuspensionOnExtensionUnload is flaky

Project Member Reported by lazyboy@chromium.org, Aug 23

Issue description

Sample failure while I tried to debug/run locally:

[ RUN      ] ServiceWorkerTestWithJSBindings/ServiceWorkerTest.ServiceWorkerSuspensionOnExtensionUnload001/0
[14755:14755:0823/112135.869638:WARNING:password_store_factory.cc(261)] Using basic (unencrypted) store for password storage. See https://chromium.googlesource.com/chromium/src/+/master/docs/linux_password_storage.md for more information about password storage options.
[14755:14755:0823/112136.079373:WARNING:gaia_auth_fetcher.cc(931)] Could not reach Google Accounts servers: errno -11
[14795:14795:0823/112136.689010:WARNING:ipc_message_attachment_set.cc(49)] MessageAttachmentSet destroyed with unconsumed attachments: 0/1
[14795:14795:0823/112136.689096:WARNING:ipc_message_attachment_set.cc(49)] MessageAttachmentSet destroyed with unconsumed attachments: 0/1
[14755:14755:0823/112136.892979:WARNING:gaia_auth_fetcher.cc(931)] Could not reach Google Accounts servers: errno -11
[14755:14755:0823/112137.710136:ERROR:service_worker_manager.cc(41)] ServiceWorkerManager::OnExtensionUninstalled
[14755:14755:0823/112137.865113:WARNING:extension_protocols.cc(472)] Failed to get directory for extension nmeilepkbkocldhelmgmbokiojnjlcpi
[14755:14769:0823/112137.865337:FATAL:service_worker_new_script_loader.cc(320)] Check failed: network_loader_state_ == NetworkLoaderState::kWaitingForBody || network_loader_state_ == NetworkLoaderState::kLoadingBody. 
#0 0x7f8b595ef3ec base::debug::StackTrace::StackTrace()
#1 0x7f8b5951a1ab logging::LogMessage::~LogMessage()
#2 0x7f8b554f4697 content::ServiceWorkerNewScriptLoader::OnComplete()
#3 0x7f8b54bc0131 network::mojom::URLLoaderClientStubDispatch::Accept()
#4 0x7f8b596dd5a2 mojo::InterfaceEndpointClient::HandleValidatedMessage()
#5 0x7f8b596dce86 mojo::FilterChain::Accept()
#6 0x7f8b596deab2 mojo::InterfaceEndpointClient::HandleIncomingMessage()
#7 0x7f8b596e575c mojo::internal::MultiplexRouter::ProcessIncomingMessage()
#8 0x7f8b596e4b30 mojo::internal::MultiplexRouter::Accept()
#9 0x7f8b596dce86 mojo::FilterChain::Accept()
#10 0x7f8b596d74bb mojo::Connector::ReadSingleMessage()
#11 0x7f8b596d8084 mojo::Connector::ReadAllAvailableMessages()
#12 0x7f8b596d7ee6 mojo::Connector::OnHandleReadyInternal()
#13 0x7f8b596d8894 mojo::SimpleWatcher::DiscardReadyState()
#14 0x7f8b5981ead3 mojo::SimpleWatcher::OnHandleReady()
#15 0x7f8b5981f04e _ZN4base8internal7InvokerINS0_9BindStateIMN4mojo13SimpleWatcherEFvijRKNS3_18HandleSignalsStateEEJNS_7WeakPtrIS4_EEijS5_EEEFvvEE7RunImplIRKS9_RKNSt3__15tupleIJSB_ijS5_EEEJLm0ELm1ELm2ELm3EEEEvOT_OT0_NSI_16integer_sequenceImJXspT1_EEEE
#16 0x7f8b594faa9d base::debug::TaskAnnotator::RunTask()
#17 0x7f8b595281fe base::MessageLoop::RunTask()
#18 0x7f8b595286c2 base::MessageLoop::DoWork()
#19 0x7f8b59612bf9 base::MessagePumpLibevent::Run()
#20 0x7f8b59527cd1 base::MessageLoop::Run()
#21 0x7f8b5955c276 base::RunLoop::Run()
#22 0x7f8b595b757a base::Thread::Run()
#23 0x7f8b55062cd4 content::BrowserProcessSubThread::IOThreadRun()
#24 0x7f8b55062c1f content::BrowserProcessSubThread::Run()
#25 0x7f8b595b7b37 base::Thread::ThreadMain()
#26 0x7f8b5960511f base::(anonymous namespace)::ThreadFunc()
#27 0x7f8b4d487494 start_thread
#28 0x7f8b4b3daa8f clone

 
Status: Started (was: Assigned)
I see two kinds of failures:

1) Frequent: inside SW code:
When an extension is uninstalled, we hit this DCHECK

void ServiceWorkerNewScriptLoader::OnComplete(
    const network::URLLoaderCompletionStatus& status) {
  DCHECK(network_loader_state_ == NetworkLoaderState::kWaitingForBody ||
         network_loader_state_ == NetworkLoaderState::kLoadingBody);
...

The code that serves the script in extension_protocols.cc is:

ExtensionURLLoaderFactory::CreateLoaderAndStart() ..

    base::FilePath directory_path;
    if (!GetDirectoryForExtensionURL(request.url, extension_id, extension.get(),
                                     registry->disabled_extensions(),
                                     &directory_path)) {
      client->OnComplete(network::URLLoaderCompletionStatus(net::ERR_FAILED));
      return;
    }

I *think* client->OnComplete is throwing off ServiceWorkerNewScriptLoader.
network_loader_state_ is NetworkLoaderState::kLoadingHeader at that point.

I'm speculating the DCHECK can come after once there is no error in OnComplete.
SW folks can tell better, I'll post a patch to discuss.

2) Infrequent:
StartTestFromBackgroundPage in service_worker_apitest.cc:
content::ExecuteSCriptAndExtractString doesn't return and
the test times out.

This sounds like a common pattern used in the test file and would likely
contribute to other test flakiness in the test suite, will follow up on
that...
Cc: shimazu@chromium.org
Yes we also are tracking that DCHECK failure at issue 868183.
Project Member

Comment 3 by bugdroid1@chromium.org, Aug 24

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

commit 6a3826e7d08c95991184aac451ecbc63b6967412
Author: Istiaque Ahmed <lazyboy@chromium.org>
Date: Fri Aug 24 06:52:46 2018

Fix error handling in ServiceWorkerNewScriptLoader::OnComplete

In case of an error where service worker script loading fails (e.g.
when there is an attempt to load an extension service worker script
after the extension has been uninstalled), the current code
fails DCHECK if network stack calls OnComplete with error param
right from mojom::URLLoaderFactory::CreateLoaderAndStart.

This CL changes the DCHECK to apply only for non-error case.
This should fix the flakiness of the test:
ServiceWorkerTest.ServiceWorkerSuspensionOnExtensionUnload.


Bug:  877218 , 868183
Test: Repeated aforementioned test x 500 locally, no DCHECK observed.
Change-Id: I1691771e466365477051f5ca1136f01f921a1ec8
Reviewed-on: https://chromium-review.googlesource.com/1187762
Commit-Queue: Istiaque Ahmed <lazyboy@chromium.org>
Reviewed-by: Makoto Shimazu <shimazu@chromium.org>
Reviewed-by: Matt Falkenhagen <falken@chromium.org>
Cr-Commit-Position: refs/heads/master@{#585730}
[modify] https://crrev.com/6a3826e7d08c95991184aac451ecbc63b6967412/content/browser/service_worker/service_worker_new_script_loader.cc

Project Member

Comment 4 by bugdroid1@chromium.org, Aug 28

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

commit 6475f54b562f9067a6879f122e53d8ed55e3f842
Author: Istiaque Ahmed <lazyboy@chromium.org>
Date: Tue Aug 28 04:20:21 2018

[Extension SW] Fix flakiness of tests calling StartTestFromBackgroundPage

StartTestFromBackgroundPage opens an extension background page
and then calls ExectuteScript*. It is possible that the function
we call through ExectuteScript isn't defined yet. This can cause
tests to time out.

Let the background page send a "ready" message so that browser_tests
can wait for it before proceeding to call ExectuteScript*.

Bug:  877218 
Change-Id: I637a2b69229c78dd645b7b078197b15015bf1b60
Reviewed-on: https://chromium-review.googlesource.com/1192352
Commit-Queue: Istiaque Ahmed <lazyboy@chromium.org>
Reviewed-by: Karan Bhatia <karandeepb@chromium.org>
Cr-Commit-Position: refs/heads/master@{#586577}
[modify] https://crrev.com/6475f54b562f9067a6879f122e53d8ed55e3f842/chrome/browser/extensions/service_worker_apitest.cc
[modify] https://crrev.com/6475f54b562f9067a6879f122e53d8ed55e3f842/chrome/test/data/extensions/api_test/service_worker/background/background.js

Status: Fixed (was: Started)

Sign in to add a comment