Bug 196519 – [iOS] Web process gets suspended while holding locked database files

• Status: RESOLVED
• Resolution: FIXED
• Component: New Bugs

[Sihui Liu]

Web process will take process assertion for database close after <https://trac.webkit.org/changeset/242983>, but we find there is a race between web process sending "do no suspend me" message and web process actually gets suspended. The example crash trace is:

Termination Description: ASSERTIOND, com.apple.WebKi:1834 was suspended with locked system files:

Thread 0 name:  Dispatch queue: com.apple.main-thread
Thread 0 Crashed:
0   libsystem_kernel.dylib        	0x00000001ee68b93c kevent_id + 8
1   libdispatch.dylib             	0x00000001ee4ebbf0 _dispatch_kq_poll + 332 (/BuildRoot/Library/Caches/com.apple.xbs/Sources/libdispatch/libdispatch-1008.250.7/src/event/event_kevent.c:718)
2   libdispatch.dylib             	0x00000001ee4eb114 _dispatch_event_loop_poke$VARIANT$mp + 476 (/BuildRoot/Library/Caches/com.apple.xbs/Sources/libdispatch/libdispatch-1008.250.7/src/event/event_kevent.c:1644)
3   JavaScriptCore                	0x00000001f660014c WTF::WorkQueue::dispatch(WTF::Function<void ()>&&) + 140 (/BuildRoot/Library/Caches/com.apple.xbs/Sources/WTF/WTF-7607.2.3/wtf/cocoa/WorkQueueCocoa.cpp:36)
4   WebKit                        	0x00000001fe969208 IPC::Connection::sendMessage(std::__1::unique_ptr<IPC::Encoder, std::__1::default_delete<IPC::Encoder> >, WTF::OptionSet<IPC::SendOption>) + 292 (/BuildRoot/Library/Caches/com.apple.xbs/Sources/WebKit2/WebKit2-7607.2.3/Platform/IPC/Connection.cpp:434)
5   WebKit                        	0x00000001fea698b8 bool IPC::Connection::send<Messages::WebProcessProxy::SetIsHoldingLockedFiles>(Messages::WebProcessProxy::SetIsHoldingLockedFiles&&, unsigned long long, WTF::OptionSet<IPC::SendOption>) + 112 (/BuildRoot/Library/Caches/com.apple.xbs/Sources/WebKit2/WebKit2-7607.2.3/Platform/IPC/Connection.h:411)
6   WebKit                        	0x00000001fea69814 WebKit::WebSQLiteDatabaseTracker::hysteresisUpdated(PAL::HysteresisState) + 64 (/BuildRoot/Library/Caches/com.apple.xbs/Sources/WebKit2/WebKit2-7607.2.3/Shared/WebSQLiteDatabaseTracker.cpp:73)

Thread 8 name:  WebCore: Database
Thread 8:
0   libsystem_kernel.dylib        	0x00000001ee68b7f8 guarded_close_np + 8
1   libsqlite3.dylib              	0x00000001eef9cd38 unixShmPurge + 568 (/BuildRoot/Library/Caches/com.apple.xbs/Sources/SQLite/SQLite-274.22/derived_source/sqlite3.c:34950)
2   libsqlite3.dylib              	0x00000001eef97af4 unixShmUnmap + 356 (/BuildRoot/Library/Caches/com.apple.xbs/Sources/SQLite/SQLite-274.22/derived_source/sqlite3.c:40100)
3   libsqlite3.dylib              	0x00000001eef577d4 sqlite3WalClose + 644 (/BuildRoot/Library/Caches/com.apple.xbs/Sources/SQLite/SQLite-274.22/derived_source/sqlite3.c:22063)
4   libsqlite3.dylib              	0x00000001eef57338 sqlite3PagerClose + 320 (/BuildRoot/Library/Caches/com.apple.xbs/Sources/SQLite/SQLite-274.22/derived_source/sqlite3.c:60327)
5   libsqlite3.dylib              	0x00000001eef56cb4 sqlite3BtreeClose + 368 (/BuildRoot/Library/Caches/com.apple.xbs/Sources/SQLite/SQLite-274.22/derived_source/sqlite3.c:70983)
6   libsqlite3.dylib              	0x00000001eef7bcd0 sqlite3LeaveMutexAndCloseZombie + 256 (/BuildRoot/Library/Caches/com.apple.xbs/Sources/SQLite/SQLite-274.22/derived_source/sqlite3.c:154776)
7   libsqlite3.dylib              	0x00000001eef8485c sqlite3Close + 688 (/BuildRoot/Library/Caches/com.apple.xbs/Sources/SQLite/SQLite-274.22/derived_source/sqlite3.c:154711)
8   WebCore                       	0x00000001f9021afc WebCore::SQLiteDatabase::close() + 260 (./platform/sql/SQLiteDatabase.cpp:152)
9   WebCore                       	0x00000001f86ad2b0 WebCore::Database::closeDatabase() + 40 (./Modules/webdatabase/Database.cpp:442)
10  WebCore                       	0x00000001f86ad21c WebCore::Database::performClose() + 264 (./Modules/webdatabase/Database.cpp:306)
11  WebCore                       	0x00000001f86b6248 WebCore::DatabaseThread::databaseThread() + 432 (./Modules/webdatabase/DatabaseThread.cpp:121)

We see web process crashed while it is sending the SetIsHoldingLockedFiles message on the main thread.

[Sihui Liu]

<rdar://problem/49531797>

[Sihui Liu]

Created attachment 366559 [details]
Patch

[Chris Dumez]

Comment on attachment 366559 [details]
Patch

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

> Source/WebCore/platform/sql/SQLiteDatabaseTracker.cpp:45
> +bool& isProcessSuspended()

Seems weird (layer violation) to have a class in WebCore know about process suspension. Although, it is weird because if the process were suspended, it would not be able to call this function in the first place, since its code would not be running.

> Source/WebKit/WebProcess/WebProcess.cpp:1470
> +        SQLiteDatabaseTracker::isProcessSuspended() = true;

I guess "isAboutToBeSuspended" would be a more accurate name.

> Source/WebKit/WebProcess/WebProcess.cpp:1498
> +        std::lock_guard<Lock> lock(SQLiteDatabaseTracker::transactionInProgressMutex());

So the lock protects both the transaction in progress and the isProcessSuspended now? I am asking because you're locking here but not above.

> Source/WebKit/WebProcess/WebProcess.cpp:1499
> +        SQLiteDatabaseTracker::isProcessSuspended() = true;

This is not how we usually set variables in WebKit, you'd want a regular setter.

> Source/WebKit/WebProcess/WebProcess.cpp:1531
> +        std::lock_guard<Lock> lock(SQLiteDatabaseTracker::transactionInProgressMutex());

It does not read well to lock a mutex for "transactionInProgress" and then set isProcessSuspended, not transactionInProgress.

[Sihui Liu]

(In reply to Chris Dumez from comment #3)
> Comment on attachment 366559 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=366559&action=review
> 
> > Source/WebCore/platform/sql/SQLiteDatabaseTracker.cpp:45
> > +bool& isProcessSuspended()
> 
> Seems weird (layer violation) to have a class in WebCore know about process
> suspension. Although, it is weird because if the process were suspended, it
> would not be able to call this function in the first place, since its code
> would not be running.
> 

Yes it's weird but given that prepareToSuspend is not actually suspending the process, but shutting down database activities, we need to keep a state for databases activities. It's either SQLiteDatabaseTracker.cpp or DatabaseTracker.

> > Source/WebKit/WebProcess/WebProcess.cpp:1470
> > +        SQLiteDatabaseTracker::isProcessSuspended() = true;
> 
> I guess "isAboutToBeSuspended" would be a more accurate name.
> 
Okay, will change.

> > Source/WebKit/WebProcess/WebProcess.cpp:1498
> > +        std::lock_guard<Lock> lock(SQLiteDatabaseTracker::transactionInProgressMutex());
> 
> So the lock protects both the transaction in progress and the
> isProcessSuspended now? I am asking because you're locking here but not
> above.
> 
Yes, will add to it.

> > Source/WebKit/WebProcess/WebProcess.cpp:1499
> > +        SQLiteDatabaseTracker::isProcessSuspended() = true;
> 
> This is not how we usually set variables in WebKit, you'd want a regular
> setter.
> 

Okay.

> > Source/WebKit/WebProcess/WebProcess.cpp:1531
> > +        std::lock_guard<Lock> lock(SQLiteDatabaseTracker::transactionInProgressMutex());
> 
> It does not read well to lock a mutex for "transactionInProgress" and then
> set isProcessSuspended, not transactionInProgress.

Will change this name, probably "SQLiteDatabaseTrackerMutex".

[Sihui Liu]

Created attachment 366618 [details]
Patch

[Chris Dumez]

Comment on attachment 366618 [details]
Patch

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

> Source/WebCore/platform/sql/SQLiteDatabaseTracker.cpp:46
> +bool isAboutToSuspend()

Again, I still do not think WebCore should know anything about process suspension. This is a WebKit2 concept and should stay at WebKit layer, not WebCore.

[Chris Dumez]

Comment on attachment 366618 [details]
Patch

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

> Source/WebCore/platform/sql/SQLiteDatabaseTracker.cpp:38
> +static bool s_isAboutToSuspend = false;

We do not use prefixes for statics in WebKit. The code above is bad coding style, let's not replicate it.

>> Source/WebCore/platform/sql/SQLiteDatabaseTracker.cpp:46
>> +bool isAboutToSuspend()
> 
> Again, I still do not think WebCore should know anything about process suspension. This is a WebKit2 concept and should stay at WebKit layer, not WebCore.

I guess if you want to keep this layering, you can simply use a name that makes sense in WebCore. Given what this boolean actually does, I would call it something like:
isDatabaseOpeningForbidden()

> Source/WebKit/WebProcess/WebProcess.cpp:1469
> +    if (!SQLiteDatabaseTracker::hasTransactionInProgress()) {

Seems wrong to call this without locking since it relies on s_transactionInProgressCounter.

Also, why are we doing this only if there are no transactions in progress?

> Source/WebKit/WebProcess/WebProcess.cpp:1499
> +        std::lock_guard<Lock> lock(SQLiteDatabaseTracker::SQLiteDatabaseTrackerMutex());

Seems aggressive to hold this lock while calling closeAllDatabases(). If closeAllDatabases() were to lock the mutex, we would deadlock.

We have some unnecessary code duplication now, you close the database here and in actualPrepareToSuspend(). However, actualPrepareToSuspend() gets called 2 lines below.

[Sihui Liu]

Created attachment 366741 [details]
Patch

[Sihui Liu]

Comment on attachment 366741 [details]
Patch

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

> Source/WebCore/platform/sql/SQLiteDatabase.cpp:89
> +        if (SQLiteDatabaseTracker::canOpenDatabase()) {

Should be !SQLiteDatabaseTracker::canOpenDatabase() here!

[Chris Dumez]

Comment on attachment 366741 [details]
Patch

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

> Source/WebCore/platform/sql/SQLiteDatabaseTracker.cpp:40
> +Lock& SQLiteDatabaseTrackerMutex()

SQLiteDatabaseTracker does not need to know anything about this. Since this is a WK2 suspension issue, the logic should go into WebSQLiteDatabaseTracker instead.

> Source/WebCore/platform/sql/SQLiteDatabaseTracker.cpp:48
> +    return isSQLiteDatabaseTrackerActive;

Right now, you're using a single boolean to mean 2 things:
- Do not allow opening databases
- Do not send IPC about locked files

I would suggest using 2 separate mechanisms instead:
1. A static boolean on SQLiteDatabase for preventing opening
2. Destroying WebProcess::m_webSQLiteDatabaseTracker whenever a suspension is requested to prevent IPC sending. Re-construct WebProcess::m_webSQLiteDatabaseTracker when resumed.

For 2, it will require making WebProcess::m_webSQLiteDatabaseTracker a std::unique_ptr. It will also require adding a destructor to WebSQLiteDatabaseTracker that:
- Unregisters itself as a client from SQLiteDatabaseTracker (SQLiteDatabaseTracker::setClient() should be updated to allow setting client to null)
- Sends WebProcessProxy::SetIsHoldingLockedFiles(false) IPC if m_hysteresis is running on destruction.

> Source/WebCore/platform/sql/SQLiteDatabaseTracker.cpp:95
> +void clearTransactionInProgressCount()

The inconsistency with the methods above bothers me. Normally, these methods do their own locking. Here, it seems you expect the caller to hold the lock, this is very error-prone.

[EWS Watchlist]

Comment on attachment 366741 [details]
Patch

Attachment 366741 [details] did not pass mac-ews (mac):
Output: https://webkit-queues.webkit.org/results/11768417

Number of test failures exceeded the failure limit.

[EWS Watchlist]

Created attachment 366752 [details]
Archive of layout-test-results from ews101 for mac-highsierra

The attached test failures were seen while running run-webkit-tests on the mac-ews.
Bot: ews101  Port: mac-highsierra  Platform: Mac OS X 10.13.6

[EWS Watchlist]

Comment on attachment 366741 [details]
Patch

Attachment 366741 [details] did not pass mac-wk2-ews (mac-wk2):
Output: https://webkit-queues.webkit.org/results/11768373

Number of test failures exceeded the failure limit.

[EWS Watchlist]

Created attachment 366753 [details]
Archive of layout-test-results from ews107 for mac-highsierra-wk2

The attached test failures were seen while running run-webkit-tests on the mac-wk2-ews.
Bot: ews107  Port: mac-highsierra-wk2  Platform: Mac OS X 10.13.6

[EWS Watchlist]

Comment on attachment 366741 [details]
Patch

Attachment 366741 [details] did not pass ios-sim-ews (ios-simulator-wk2):
Output: https://webkit-queues.webkit.org/results/11768167

Number of test failures exceeded the failure limit.

[EWS Watchlist]

Created attachment 366755 [details]
Archive of layout-test-results from ews122 for ios-simulator-wk2

The attached test failures were seen while running run-webkit-tests on the ios-sim-ews.
Bot: ews122  Port: ios-simulator-wk2  Platform: Mac OS X 10.13.6

[EWS Watchlist]

Comment on attachment 366741 [details]
Patch

Attachment 366741 [details] did not pass mac-debug-ews (mac):
Output: https://webkit-queues.webkit.org/results/11768381

Number of test failures exceeded the failure limit.

[EWS Watchlist]

Created attachment 366757 [details]
Archive of layout-test-results from ews115 for mac-highsierra

The attached test failures were seen while running run-webkit-tests on the mac-debug-ews.
Bot: ews115  Port: mac-highsierra  Platform: Mac OS X 10.13.6

[EWS Watchlist]

Comment on attachment 366741 [details]
Patch

Attachment 366741 [details] did not pass win-ews (win):
Output: https://webkit-queues.webkit.org/results/11770483

Number of test failures exceeded the failure limit.

[EWS Watchlist]

Created attachment 366769 [details]
Archive of layout-test-results from ews201 for win-future

The attached test failures were seen while running run-webkit-tests on the win-ews.
Bot: ews201  Port: win-future  Platform: CYGWIN_NT-10.0-2.11.1-0.329-5-3-x86_64-64bit

[Sihui Liu]

Created attachment 366782 [details]
Patch

[Chris Dumez]

Comment on attachment 366782 [details]
Patch

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

Almost perfect. One last round.

> Source/WebCore/platform/sql/SQLiteDatabase.cpp:83
> +{

I think we should lock in here so that callers do know have to worry about locking and so that we do not need to expose the mutex.

> Source/WebCore/platform/sql/SQLiteDatabase.h:142
> +    WEBCORE_EXPORT static Lock& isDatabaseOpeningForbiddenMutex();

I do not think we need to expose this or have it in the header. It should just be a static in the cpp file.

> Source/WebCore/platform/sql/SQLiteDatabaseTracker.cpp:60
> +    std::lock_guard<Lock> lock(transactionInProgressMutex);

Can you add such lock to hasTransactionInProgress() as well?

> Source/WebKit/Shared/WebSQLiteDatabaseTracker.cpp:57
> +    ASSERT(isMainThread());

ASSERT(RunLoop::isMain()); since we are at WebKit layer.

> Source/WebKit/Shared/WebSQLiteDatabaseTracker.cpp:61
> +        m_hysteresis.stop();

Calling stop() will not synchronously call WebSQLiteDatabaseTracker::hysteresisUpdated(), it will schedule a timer to call it. But then, your destructor will finish running and m_hysteresis will be destroyed. As a result you will not be sending the WebProcessProxy::SetIsHoldingLockedFiles() IPC you should bee sending. I would suggest calling hysteresisUpdated(HysteresisState::Stopped) directly.

> Source/WebKit/WebProcess/WebProcess.cpp:1466
> +        std::lock_guard<Lock> lock(SQLiteDatabase::isDatabaseOpeningForbiddenMutex());

No need with my proposal.

> Source/WebKit/WebProcess/WebProcess.cpp:1516
> +        std::lock_guard<Lock> lock(SQLiteDatabase::isDatabaseOpeningForbiddenMutex());

No need with my proposal.

> Source/WebKit/WebProcess/WebProcess.cpp:1592
> +        std::lock_guard<Lock> lock(SQLiteDatabase::isDatabaseOpeningForbiddenMutex());

No need with my proposal.

> Source/WebKit/WebProcess/WebProcess.h:502
> +    std::unique_ptr<WebSQLiteDatabaseTracker> m_webSQLiteDatabaseTracker;

WebSQLiteDatabaseTracker can probably be forward-declared now.

[Sihui Liu]

Comment on attachment 366782 [details]
Patch

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

>> Source/WebCore/platform/sql/SQLiteDatabase.cpp:83
>> +{
> 
> I think we should lock in here so that callers do know have to worry about locking and so that we do not need to expose the mutex.

Cool!

>> Source/WebCore/platform/sql/SQLiteDatabase.h:142
>> +    WEBCORE_EXPORT static Lock& isDatabaseOpeningForbiddenMutex();
> 
> I do not think we need to expose this or have it in the header. It should just be a static in the cpp file.

Right.

>> Source/WebCore/platform/sql/SQLiteDatabaseTracker.cpp:60
>> +    std::lock_guard<Lock> lock(transactionInProgressMutex);
> 
> Can you add such lock to hasTransactionInProgress() as well?

Will add.

>> Source/WebKit/Shared/WebSQLiteDatabaseTracker.cpp:57
>> +    ASSERT(isMainThread());
> 
> ASSERT(RunLoop::isMain()); since we are at WebKit layer.

Okay.

>> Source/WebKit/Shared/WebSQLiteDatabaseTracker.cpp:61
>> +        m_hysteresis.stop();
> 
> Calling stop() will not synchronously call WebSQLiteDatabaseTracker::hysteresisUpdated(), it will schedule a timer to call it. But then, your destructor will finish running and m_hysteresis will be destroyed. As a result you will not be sending the WebProcessProxy::SetIsHoldingLockedFiles() IPC you should bee sending. I would suggest calling hysteresisUpdated(HysteresisState::Stopped) directly.

Good find!

>> Source/WebKit/WebProcess/WebProcess.cpp:1466
>> +        std::lock_guard<Lock> lock(SQLiteDatabase::isDatabaseOpeningForbiddenMutex());
> 
> No need with my proposal.

Yes.

>> Source/WebKit/WebProcess/WebProcess.cpp:1516
>> +        std::lock_guard<Lock> lock(SQLiteDatabase::isDatabaseOpeningForbiddenMutex());
> 
> No need with my proposal.

Yes.

>> Source/WebKit/WebProcess/WebProcess.cpp:1592
>> +        std::lock_guard<Lock> lock(SQLiteDatabase::isDatabaseOpeningForbiddenMutex());
> 
> No need with my proposal.

Yes.

>> Source/WebKit/WebProcess/WebProcess.h:502
>> +    std::unique_ptr<WebSQLiteDatabaseTracker> m_webSQLiteDatabaseTracker;
> 
> WebSQLiteDatabaseTracker can probably be forward-declared now.

Okay.

[Sihui Liu]

Created attachment 366817 [details]
Patch

[Chris Dumez]

Comment on attachment 366817 [details]
Patch

Very nice.

[WebKit Commit Bot]

Comment on attachment 366817 [details]
Patch

Clearing flags on attachment: 366817

Committed r243939: <https://trac.webkit.org/changeset/243939>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.

[Shawn Roberts]

After this change we are seeing an Assertion failure in iOS Simulator Debug and it's causing at least 5 crashes and I believe several of the failures 

See: https://build.webkit.org/results/Apple%20iOS%2012%20Simulator%20Debug%20WK2%20(Tests)/r243941%20(3162)/results.html#

Assertion: 

ASSERTION FAILED: !staticTracker
./Modules/webdatabase/DatabaseTracker.cpp(77) : static void WebCore::DatabaseTracker::initializeTracker(const WTF::String &)
1   0x205442679 WTFCrash
2   0x209538d2b WTFCrashWithInfo(int, char const*, char const*, int)
3   0x20afc9b90 WebCore::DatabaseTracker::initializeTracker(WTF::String const&)
4   0x20afc9b26 WebCore::DatabaseManager::initialize(WTF::String const&)
5   0x106284f7b WebKit::WebProcess::setWebsiteDataStoreParameters(WebKit::WebProcessDataStoreParameters&&)
6   0x1068c3b8a void IPC::callMemberFunctionImpl<WebKit::WebProcess, void (WebKit::WebProcess::*)(WebKit::WebProcessDataStoreParameters&&), std::__1::tuple<WebKit::WebProcessDataStoreParameters>, 0ul>(WebKit::WebProcess*, void (WebKit::WebProcess::*)(WebKit::WebProcessDataStoreParameters&&), std::__1::tuple<WebKit::WebProcessDataStoreParameters>&&, std::__1::integer_sequence<unsigned long, 0ul>)

[Sihui Liu]

Created attachment 366855 [details]
Patch

[Sihui Liu]

Created attachment 366857 [details]
Patch

[WebKit Commit Bot]

Comment on attachment 366857 [details]
Patch

Clearing flags on attachment: 366857

Committed r243957: <https://trac.webkit.org/changeset/243957>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.