DOMStorage flakily fails to flush its DB on shutdown (was: ProfileManagerBrowserTest.DeleteAllProfiles is flaky) |
|||||||
Issue descriptionhttps://build.chromium.org/p/tryserver.chromium.win/builders/win10_chromium_x64_rel_ng/builds/798 https://luci-logdog.appspot.com/v/?s=chromium%2Fbb%2Ftryserver.chromium.win%2Fwin10_chromium_x64_rel_ng%2F798%2F%2B%2Frecipes%2Fsteps%2Fbrowser_side_navigation_browser_tests__with_patch__on_Windows-10-10586%2F0%2Flogs%2FProfileManagerBrowserTest.DeleteAllProfiles%2F0 [ RUN ] ProfileManagerBrowserTest.DeleteAllProfiles [4920:5664:0323/093019.787:WARNING:url_request_context_getter.cc(43)] URLRequestContextGetter leaking due to no owning thread. [4920:5664:0323/093019.798:FATAL:task_tracker.cc(394)] Check failed: !shutdown_event_->IsSignaled(). Backtrace: base::debug::StackTrace::StackTrace [0x00007FF698AADC15+69] base::debug::StackTrace::StackTrace [0x00007FF698A688D3+19] logging::LogMessage::~LogMessage [0x00007FF698A03DEA+74] base::internal::TaskTracker::BeforePostTask [0x00007FF698AD98D0+224] base::internal::TaskTracker::WillPostTask [0x00007FF698ADACA0+112] base::internal::SchedulerWorkerPoolImpl::PostTaskWithSequence [0x00007FF698AD6F02+194] base::internal::SchedulerWorkerPoolImpl::SchedulerWorkerDelegateImpl::OnMainEntry [0x00007FF698AD6E08+1112] base::SequencedWorkerPool::Inner::PostTaskToTaskScheduler [0x00007FF698A32BCF+367] base::SequencedWorkerPool::Inner::PostTask [0x00007FF698A32716+886] base::SequencedWorkerPool::PoolSequencedTaskRunner::PostDelayedTask [0x00007FF698A32189+121] base::TaskRunner::PostTask [0x00007FF698A19A67+23] content::DOMStorageWorkerPoolTaskRunner::PostShutdownBlockingTask [0x00007FF6978D0301+49] content::DOMStorageContextImpl::~DOMStorageContextImpl [0x00007FF6978C2A81+273] content::DOMStorageContextImpl::`vector deleting destructor' [0x00007FF6978C2C84+20] base::ReleaseHelper<storage::BlobDataHandle::BlobDataHandleShared>::DoRelease [0x00007FF697CEE022+50] content::DOMStorageContextWrapper::~DOMStorageContextWrapper [0x00007FF6978C7B30+48] content::DOMStorageContextWrapper::`vector deleting destructor' [0x00007FF6978C7BE4+20] scoped_refptr<content::DOMStorageContextWrapper>::Release [0x00007FF69C00DB33+51] base::internal::BindState<void (__cdecl*)(scoped_refptr<content::DOMStorageContextWrapper> const & __ptr64,scoped_refptr<storage::SpecialStoragePolicy> const & __ptr64,base::Callback<bool __cdecl(GURL const & __ptr64,storage::SpecialStoragePolicy * __ptr6 [0x00007FF697BA6B70+32] base::internal::BindState<void (__cdecl*)(base::Callback<void __cdecl(std::vector<content::SessionStorageUsageInfo,std::allocator<content::SessionStorageUsageInfo> > const & __ptr64),1,1> const & __ptr64,std::vector<content::SessionStorageUsageInfo,std::a [0x00007FF6978C803B+27] base::PendingTask::~PendingTask [0x00007FF698AB2D52+18] base::MessageLoop::DeletePendingTasks [0x00007FF698A154C4+212] base::MessageLoop::~MessageLoop [0x00007FF698A142D6+310] base::MessageLoop::`vector deleting destructor' [0x00007FF6989543E4+20] content::BrowserMainLoop::~BrowserMainLoop [0x00007FF69784563B+875] content::BrowserMainLoop::`vector deleting destructor' [0x00007FF697845664+20] content::BrowserMainRunnerImpl::Shutdown [0x00007FF69784B77D+829] content::BrowserMain [0x00007FF697844CC3+179] content::RunNamedProcessTypeMain [0x00007FF6989E7729+265] content::ContentMainRunnerImpl::Run [0x00007FF6989E75BD+365] service_manager::Main [0x00007FF699B26CDC+348] content::ContentMain [0x00007FF6989E6B0C+44] content::BrowserTestBase::SetUp [0x00007FF698BE7B73+1763] InProcessBrowserTest::SetUp [0x00007FF698AE976F+447] testing::internal::HandleExceptionsInMethodIfSupported<testing::Test,void> [0x00007FF699228CFD+61] testing::Test::Run [0x00007FF69923411A+74] testing::TestInfo::Run [0x00007FF699234341+161] testing::TestCase::Run [0x00007FF699234225+165] testing::internal::UnitTestImpl::RunAllTests [0x00007FF6992346F2+562] testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl,bool> [0x00007FF699228D9D+61] testing::UnitTest::Run [0x00007FF699234489+217] base::TestSuite::Run [0x00007FF698B00A69+137] ChromeTestSuiteRunner::RunTestSuite [0x00007FF69BFB175D+45] content::LaunchTests [0x00007FF698BDDB82+690] LaunchChromeTests [0x00007FF69BFB16FE+94] main [0x00007FF69BFB137F+83] __scrt_common_main_seh [0x00007FF69BF50669+285] (f:\ddctools\crtcstartup\src\startup\exe_common.inl:253) BaseThreadInitThunk [0x00007FF8A7308102+34] RtlUserThreadStart [0x00007FF8A7A2C574+52]
,
Mar 31 2017
Maybe we should get rid of PostShutdownBlockingTask() instead, since we can't rely on it blocking shutdown (e.g. android) anyhow?
,
Mar 31 2017
I would eventually like to get to a world where we flush BLOCK_SHUTDOWN work on Android when the app receives a notification of being switched out/etc. When everything has been migrated to TaskScheduler: everything can be flushed in one pass (no need to wind things down one thread at a time) and I'd like to make shutdown atomic (shutdown phase without winding down any threads than terminate process) -- perhaps we can one day dream of being able to go through that without even entering any kind of "shutdown" state. All of that to say, I'm all for simplifying shutdown itself but I'd prefer we don't stop marking tasks BLOCK_SHUTDOWN when they should *ideally* block shutdown. And this particular DCHECK is saying "hey you wanted this work to block shutdown but shutdown is already done... if it needs to block shutdown then you should have posted it earlier... and if it doesn't need to then don't post it as such.."
,
Mar 31 2017
,
May 2 2017
Looking at this closer, this is a new check which is catching a real DOMStorage bug. The issue: * ~DOMStorageContextImpl() attempts to post a block shutdown task to the BlockingPool to trigger ~SessionStorageDatabase which is ultimately intended to trigger ~DBImpl::~DBImpl() which is expected to "// Wait for background work to finish" * but... it's possible that ~DOMStorageContextImpl() runs way too late (in this case when the SessionStorageUsageInfo which indirectly owns the last reference to it is dropped from the main MessageLoop's pending tasks in the last stages of shutdown [1] [1] on shutdown: the main MessageLoop stops running tasks early in the shutdown phase, then BrowserMainLoop::ShutdownThreadsAndCleanUp() happens (after which posting a BLOCK_SHUTDOWN task to a pool will result in the check that happens in this bug), and at the very end the main MessageLoop is deleted (and brings the remaining tasks, posted to it too late, down with itself). If DBImpl() really needs to block shutdown on it being flushed, it currently flakily doesn't =S... This seems high priority to fix because it (1) triggers a DCHECK and (2) might result in corrupted DOMStorage DB or loss of data?
,
May 2 2017
I think we can fix this by scheduling the required work in the DOMStorageContextImpl::Shutdown() method.
,
May 4 2017
Probably, except that DOMStorageContextImpl::Shutdown() appears to be triggered from ~StoragePartitionImpl() which is potentially too late as well (appears to be ultimately hooked on BrowserContext which is also deleted late I think). Essentially nothing should rely on tear down to flush IMO.
,
Mar 20 2018
mek@, can you take a peek?
,
Mar 23 2018
Has this actually caused any more test flakiness? One thing I don't understand is the various comments here mentioning that destroying a SessionStorageUsageInfo object somehow triggers tasks being posted. It doesn't look like that struct contains now or has ever contained anything with non-trivial destructors that might do such a thing... Anyway, if this isn't currently causing major test problems, I'd hesitate to spend much time fixing it, at least until dmurphs session storage mojofication efforts are done, as that's all going to change the shutdown code paths anyway. There is definitely a bigger problem with it being hard to guarantee that data actually gets flushed to disk on shutdown, but I'm having trouble parsing the messages in this thread with what the code actually looks like/used to look like to figure out what the problem being discussed in this particular bug is...
,
Mar 23 2018
,
Jan 15
I'm unlikely to be able to spend any time on this any time soon, so unassigning from myself. |
|||||||
►
Sign in to add a comment |
|||||||
Comment 1 by pa...@yandex-team.ru
, Mar 31 2017