New issue
Advanced search Search tips

Issue 776711 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Closed: Nov 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Linux , Windows
Pri: 2
Type: Bug

Blocking:
issue 769425



Sign in to add a comment

BrowsingDataRemoverBrowserTest.ServiceWorkerDeletion is flaky

Project Member Reported by dullweber@chromium.org, Oct 20 2017

Issue description

Project Member

Comment 1 by bugdroid1@chromium.org, Oct 20 2017

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

commit d902e59f3e9c76c8463c1c2c52bb8a6849a8bf55
Author: Christian Dullweber <dullweber@chromium.org>
Date: Fri Oct 20 13:00:51 2017

Disable flaky BrowsingDataRemoverBrowserTest.ServiceWorkerDeletion test

This recently added test seems to be flaky on all platforms.

Bug:  776711 
Change-Id: Ibd6e3c74c164590b0079a712a21ac4fcf2f34ba2
Reviewed-on: https://chromium-review.googlesource.com/730706
Reviewed-by: Christian Dullweber <dullweber@chromium.org>
Reviewed-by: Martin Šrámek <msramek@chromium.org>
Cr-Commit-Position: refs/heads/master@{#510413}
[modify] https://crrev.com/d902e59f3e9c76c8463c1c2c52bb8a6849a8bf55/chrome/browser/browsing_data/browsing_data_remover_browsertest.cc

Project Member

Comment 2 by bugdroid1@chromium.org, Oct 24 2017

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

commit 3753d09b8ab48b9fbf85efb49279788876ac2a7a
Author: Christian Dullweber <dullweber@chromium.org>
Date: Tue Oct 24 13:34:52 2017

Fix ServiceWorker test

To fix flakiness, wait until the service worker is actually ready before 
telling the test that the service worker is installed.
Service workers from subdirectories can't be used because they will
never be reported as ready because the scope of a service worker is 
defined by the directory it is in.

Bug:  776711 
Change-Id: I997f0b10b917251e20003eefa6d40e76f52edb21
Reviewed-on: https://chromium-review.googlesource.com/730965
Reviewed-by: Martin Šrámek <msramek@chromium.org>
Commit-Queue: Christian Dullweber <dullweber@chromium.org>
Cr-Commit-Position: refs/heads/master@{#511130}
[modify] https://crrev.com/3753d09b8ab48b9fbf85efb49279788876ac2a7a/chrome/browser/browsing_data/browsing_data_remover_browsertest.cc
[add] https://crrev.com/3753d09b8ab48b9fbf85efb49279788876ac2a7a/content/test/data/browsing_data/empty_worker.js
[rename] https://crrev.com/3753d09b8ab48b9fbf85efb49279788876ac2a7a/content/test/data/browsing_data/site_data.html

Status: Fixed (was: Started)

Comment 4 by msw@chromium.org, Oct 24 2017

Components: Tests>Flaky
Labels: OS-Linux
Status: Assigned (was: Fixed)
This just flaked again, please take another look, thanks:
  https://build.chromium.org/p/chromium.linux/builders/Linux%20Tests/builds/63735
Blocking: 769425
I'm disabling the test again: https://crrev.com/c/737799

It looks like the deletion of a service worker sometimes takes too long and GetSiteDataCount still sees the registration.

Project Member

Comment 6 by bugdroid1@chromium.org, Oct 25 2017

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

commit 4bfa2ec1b1fdc5c7d99a3535126e45740220ff7b
Author: Christian Dullweber <dullweber@chromium.org>
Date: Wed Oct 25 10:55:17 2017

Disable ServiceWorker test again

The ServiceWorkerDeletion test is still flaky. This time deletions are
not registered in time and GetSiteDataCount() still sees a service
worker registration after a deletion.

Bug:  776711 
Change-Id: Iae67335a91b1d6b98c312e4fc4dc82e76c9728a4
Reviewed-on: https://chromium-review.googlesource.com/737799
Reviewed-by: Martin Šrámek <msramek@chromium.org>
Commit-Queue: Christian Dullweber <dullweber@chromium.org>
Cr-Commit-Position: refs/heads/master@{#511413}
[modify] https://crrev.com/4bfa2ec1b1fdc5c7d99a3535126e45740220ff7b/chrome/browser/browsing_data/browsing_data_remover_browsertest.cc

Labels: -Pri-3 OS-Windows Pri-2
Happens on Windows too: https://build.chromium.org/p/tryserver.chromium.win/builders/win10_chromium_x64_rel_ng/builds/12595

Giving this bug a bit more priority, as it is causing CQ to randomly fail for others.
Cc: msramek@chromium.org
There seems to be an actual bug with the interaction of service-worker deletions and the quota manager:

Usually there are two calls to QuotaDatabase::SetOriginLastModifiedTime, followed by one call to DeleteOriginInfo
[36534:36559:1108/165218.256966:ERROR:quota_database.cc(274)] SetOriginLastModifiedTime
[36534:36557:1108/165218.257416:ERROR:quota_database.cc(274)] SetOriginLastModifiedTime
[36534:36557:1108/165218.257568:ERROR:quota_database.cc(431)] DeleteOriginInfo

In cases, where the test flakes, the order is different: 

[36631:36651:1108/165221.482061:ERROR:quota_database.cc(274)] SetOriginLastModifiedTime
[36631:36651:1108/165221.482249:ERROR:quota_database.cc(431)] DeleteOriginInfo 
[36631:36651:1108/165221.482437:ERROR:quota_database.cc(274)] SetOriginLastModifiedTime

The last SetOriginLastModifiedTime call probably restores the entry. This means the quota manager will never return the right value.
I will investigate, why this happens.
The race condition seems to be that it is possible that OriginDataDeleter::Completed() is called before the ServiceWorker deletion is completed

Good run (C = Cache related calls, W = ServiceWorker related calls):
   storage_partition_impl.cc(810) ClearOriginsOnIOThread
   quota_manager.cc(554) QuotaManager::OriginDataDeleter()
C  cache_storage_manager.cc(421) DeleteOriginDidClose
C  quota_manager.cc(1282) NotifyStorageModifiedInternal() 0 32 0
W  service_worker_storage.cc(520) DeleteRegistration
C  quota_database.cc(275) SetOriginLastModifiedTime()
W  service_worker_storage.cc(1324) DidDeleteRegistration()
W  quota_manager.cc(1282) NotifyStorageModifiedInternal() 0 64 -203
W  quota_database.cc(275) SetOriginLastModifiedTime()
   quota_manager.cc(580) OriginDataDeleter::Completed() <---- Called at the right time
   quota_database.cc(432) DeleteOriginInfo()
   quota_database.cc(342) DeleteOriginLastEvictionTime()

Bad run:
   storage_partition_impl.cc(810) ClearOriginsOnIOThread
   quota_manager.cc(554) QuotaManager::OriginDataDeleter()
C  cache_storage_manager.cc(421) DeleteOriginDidClose
C  quota_manager.cc(1282) NotifyStorageModifiedInternal() 0 32 0
   quota_manager.cc(580) OriginDataDeleter::Completed() <---- Called too early!
W  service_worker_storage.cc(520) DeleteRegistration()
W  quota_database.cc(275) SetOriginLastModifiedTime()
   quota_database.cc(432) DeleteOriginInfo()            <---- called from OriginDataDeleter::Completed()
W  service_worker_storage.cc(1324) DidDeleteRegistration()
W  quota_manager.cc(1282) NotifyStorageModifiedInternal() 0 64 -203
W  quota_database.cc(275) SetOriginLastModifiedTime()


The issue with incorrect quota deletion seems to come from this CL: https://crrev.com/413063004

The following steps happen in ServiceWorkerUnregisterJob::OnRegistrationFound():
ResolvePromise() // Reports service worker deletion as completed.
ServiceWorkerRegistration::ClearWhenReady() // Do the actual clearing after the workers has been reported as deleted
  ServiceWorkerStorage::DeleteRegistration() 
    ServiceWorkerStorage::DidDeleteRegistration()
      QuotaManager::NotifyStorageModified()

If ServiceWorkerStorage::DeleteRegistration() finishes after the quota origin has already been removed by OriginDataDeleter::Completed(), it will recreate the quota entry.

I created a CL that changes ServiceWorkerUnregisterJob to wait until the SW registration is deleted. This should fix the race condition but there are currently some layout test issues. https://crrev.com/c/758870

Cc: falken@chromium.org
falken@:
I'm trying to fix an issue with ServiceWorker deletion that is caused by  ServiceWorkerUnregisterJob calling its callback before the registration is actually deleted and the quota manager updated. I noticed that you worked on this in https://crrev.com/413063004 and maybe you could help with this issue?

I tried to change the callback to be called later (https://crrev.com/c/758870) but it looks like two layout tests are expecting the callback to be called before the registration has been removed.

As an alternative idea, I thought about adding a second callback to ServiceWorkerUnregisterJob but that seems to be quite messy as there are now two different callbacks with only slightly different meaning (https://crrev.com/c/768417).

Do you have any suggestion how this could be improved? To correctly remove all data for an origin, all quota updates have to be executed before the quota manager can finish. 
Yes, the callback in ServiceWorkerUnregister has a particular web-exposed meaning. It resolves the unregister() promise as per the timing imposed by the spec, which can happen before actual deletion of the resources.

Adding a second callback for a test seems a bit like overkill. Could you possibly use a listener function like ServiceWorkerRegistration::Listener::OnRegistrationFinishedUninstalling()?


Thanks, adding a listener is working great. I created a CL https://crrev.com/c/771650/
Project Member

Comment 14 by bugdroid1@chromium.org, Nov 22 2017

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

commit 816eedaf2af6529416fd2403255bad5ef7874f10
Author: Christian Dullweber <dullweber@chromium.org>
Date: Wed Nov 22 15:26:44 2017

Wait until ServiceWorkers are actually deleted

When deleting all quota managed data, there is a racecondition between
ServiceWorkers updating the quota manager and the quota entry being
removed. If the entry is removed before the ServiceWorker updates its
usage, it will recreate the entry.
This CL changes ServiceWorkerContextCore::UnregisterServiceWorkers to wait
until the ServiceWorker registration is fully deleted and the quota
usage has been updated.

Bug:  776711 
Change-Id: I5158f51828d634c1dd73b079bcc4c6ecb06c4d6b
Reviewed-on: https://chromium-review.googlesource.com/771650
Reviewed-by: Martin Šrámek <msramek@chromium.org>
Reviewed-by: Matt Falkenhagen <falken@chromium.org>
Reviewed-by: Hiroki Nakagawa <nhiroki@chromium.org>
Commit-Queue: Christian Dullweber <dullweber@chromium.org>
Cr-Commit-Position: refs/heads/master@{#518637}
[modify] https://crrev.com/816eedaf2af6529416fd2403255bad5ef7874f10/chrome/browser/browsing_data/browsing_data_remover_browsertest.cc
[modify] https://crrev.com/816eedaf2af6529416fd2403255bad5ef7874f10/content/browser/service_worker/service_worker_context_core.cc
[modify] https://crrev.com/816eedaf2af6529416fd2403255bad5ef7874f10/content/browser/service_worker/service_worker_context_core.h
[modify] https://crrev.com/816eedaf2af6529416fd2403255bad5ef7874f10/content/browser/service_worker/service_worker_context_unittest.cc
[modify] https://crrev.com/816eedaf2af6529416fd2403255bad5ef7874f10/content/browser/service_worker/service_worker_context_wrapper.cc
[modify] https://crrev.com/816eedaf2af6529416fd2403255bad5ef7874f10/content/browser/service_worker/service_worker_registration.cc
[modify] https://crrev.com/816eedaf2af6529416fd2403255bad5ef7874f10/content/browser/service_worker/service_worker_registration.h

Status: Fixed (was: Assigned)
Flakiness dashboard looks all green

Sign in to add a comment