Bug 211637

<rdar://problem/63031185>

From the error log, "ERROR: SQLite database failed to set journal_mode to WAL, error: database is locked", it looks like there are conflicted transactions on the same database connection (https://www.sqlite.org/rescode.html#locked). 

As this is regression from r260791(?), it's possible a database connection is not closed properly, e.g. a connection will not be closed if there are unfinalized prepared statements(https://www.sqlite.org/c3ref/close.html).

Looking at r260791, it seems NetworkSession::recreateResourceLoadStatisticStore can be called consecutively, and m_resourceLoadStatistics will be set before task dispatched in WebResourceLoadStatisticsStore::flushAndDestroyPersistentStore is done. Not sure if this is an issue. Maybe verify by waiting in NetworkSession::recreateResourceLoadStatisticStore until the completion handler is called to see if this fixes the issue.

It may be helpful to add some logging about error code/message around the assertion.

(In reply to Sihui Liu from comment #2)

Thanks for taking a look at this.

> From the error log, "ERROR: SQLite database failed to set journal_mode to
> WAL, error: database is locked", it looks like there are conflicted
> transactions on the same database connection
> (https://www.sqlite.org/rescode.html#locked). 
> 
> As this is regression from r260791(?), it's possible a database connection
> is not closed properly, e.g. a connection will not be closed if there are
> unfinalized prepared statements(https://www.sqlite.org/c3ref/close.html).
> 

This could definitely be related. The statements are all prepared in ResourceLoadStatisticsDatabaseStore::prepareStatements(), but the unused ones are not finalized before closing.

> Looking at r260791, it seems
> NetworkSession::recreateResourceLoadStatisticStore can be called
> consecutively, and m_resourceLoadStatistics will be set before task
> dispatched in WebResourceLoadStatisticsStore::flushAndDestroyPersistentStore
> is done. Not sure if this is an issue. Maybe verify by waiting in
> NetworkSession::recreateResourceLoadStatisticStore until the completion
> handler is called to see if this fixes the issue.

Isn't this already occurring? m_resourceLoadStatistics is set in the completion handler of destroyResourceLoadStatistics, which gets passed to WebResourceLoadStatisticsStore::flushAndDestroyPersistentStore(), so it won't be set until that has finished.

Created attachment 399150 [details]
Patch

Still trying to reproduce to confirm this patch will fix the crashes, letting EWS run in the meantime.

Created attachment 399206 [details]
Patch

Still can't reproduce this crash, but this fix makes sense from a performance standpoint (we should not be recreating a memory store between two database tests).

(In reply to katherine_cheney from comment #8)
> Still can't reproduce this crash, but this fix makes sense from a
> performance standpoint (we should not be recreating a memory store between
> two database tests).

And, after talking with Sihui, I think it will likely fix the crash.

Created attachment 399263 [details]
Patch

Is testRunner.setUseITPDatabase() blocking so that the next statement after it guarantees that ITP is set up accordingly?

It uses WKWebsiteDataStoreSetUseITPDatabase which is waited for.  The actual implementation might not be waiting for everything it needs to, but waiting is happening.

(In reply to Alex Christensen from comment #12)
> It uses WKWebsiteDataStoreSetUseITPDatabase which is waited for.  The actual
> implementation might not be waiting for everything it needs to, but waiting
> is happening.

The goal of the patch is to make sure recreateResourceLoadStatisticsStore only gets called once. I don't think the call to setUseITPDatabase() waits for statisticsResetToConsisistentState() to be finished.

Committed r261659: <https://trac.webkit.org/changeset/261659>

All reviewed patches have been landed. Closing bug and clearing flags on attachment 399263 [details].

Comment on attachment 399263 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=399263&action=review

> Source/WebKit/UIProcess/API/C/WKWebsiteDataStoreRef.cpp:-663
> -    store.setUseITPDatabase(false, [callbackAggregator = callbackAggregator.copyRef()] { });

This change is wrong and is leading to flakiness in the tests... Now I have tests that give different output whether or not the test that runs right before it called testRunner.setUseITPDatabase(true) or not.

TestController::resetState() needs to resets ALL state. It is NEVER OK to rely on tests to reset state and has historically always led to flakiness. Please fix.

(In reply to Chris Dumez from comment #15)
> Comment on attachment 399263 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=399263&action=review
> 
> > Source/WebKit/UIProcess/API/C/WKWebsiteDataStoreRef.cpp:-663
> > -    store.setUseITPDatabase(false, [callbackAggregator = callbackAggregator.copyRef()] { });
> 
> This change is wrong and is leading to flakiness in the tests... Now I have
> tests that give different output whether or not the test that runs right
> before it called testRunner.setUseITPDatabase(true) or not.
> 
> TestController::resetState() needs to resets ALL state. It is NEVER OK to
> rely on tests to reset state and has historically always led to flakiness.
> Please fix.

fix: https://bugs.webkit.org/show_bug.cgi?id=212094

Interesting, do you know why the flakiness was happening based on testRunner.setUseITPDatabase(true)? I thought the original implementation seemed more likely to cause flakiness if two database tests were occurring back to back. With the reset-to-memory-store implementation, this would destruct a database store, make a memory store, destruct the memory store, then make a new database store, which did not seem right, and seemed to be contributing to database locking.

(In reply to katherine_cheney from comment #16)
> (In reply to Chris Dumez from comment #15)
> > Comment on attachment 399263 [details]
> > Patch
> > 
> > View in context:
> > https://bugs.webkit.org/attachment.cgi?id=399263&action=review
> > 
> > > Source/WebKit/UIProcess/API/C/WKWebsiteDataStoreRef.cpp:-663
> > > -    store.setUseITPDatabase(false, [callbackAggregator = callbackAggregator.copyRef()] { });
> > 
> > This change is wrong and is leading to flakiness in the tests... Now I have
> > tests that give different output whether or not the test that runs right
> > before it called testRunner.setUseITPDatabase(true) or not.
> > 
> > TestController::resetState() needs to resets ALL state. It is NEVER OK to
> > rely on tests to reset state and has historically always led to flakiness.
> > Please fix.
> 
> fix: https://bugs.webkit.org/show_bug.cgi?id=212094
> 
> Interesting, do you know why the flakiness was happening based on
> testRunner.setUseITPDatabase(true)? I thought the original implementation
> seemed more likely to cause flakiness if two database tests were occurring
> back to back. With the reset-to-memory-store implementation, this would
> destruct a database store, make a memory store, destruct the memory store,
> then make a new database store, which did not seem right, and seemed to be
> contributing to database locking.

Well, yes I know. The flakiness is happening because the previous test is setting the ITP database to true and the new test is not setting it to false. I know you tried in this patch to update tests to set the ITP database to false but it looks like some were missed. In any case, it is terrible practice to rely on tests to do clean up at the end and will always lead to flakiness, one way or another. TestController::resetState() is the central way of resetting state between tests to avoid flakiness.