197888 – The network process tries to take a process assertion when NetworkProcess::processWillSuspendImminently() is called

RESOLVED FIXED 197888

The network process tries to take a process assertion when NetworkProcess::processWillSuspendImminently() is called

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

Summary The network process tries to take a process assertion when NetworkProcess::pr...

Chris Dumez

Reported 2019-05-14 11:29:51 PDT

The network process tries to take a process assertion when NetworkProcess::processWillSuspendImminently() is called: 2019-05-14 10:59:36.691261-0700 0x29035 Error 0x6f0c5 3660 0 MobileSafari: (WebKit) [com.apple.WebKit:ProcessSuspension] Background task expired while holding WebKit ProcessAssertion (isMainThread? 1). 2019-05-14 10:59:36.695504-0700 0x2906d Default 0x0 3663 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x15bd10c80 - WebProcess::processWillSuspendImminently() 2019-05-14 10:59:36.729903-0700 0x2906d Default 0x0 3663 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] WebProcess 3663 is freezing all layer trees 2019-05-14 10:59:36.729999-0700 0x2906d Default 0x0 3663 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x15bd10c80 - WebProcess::destroyRenderingResources() took 0.01ms 2019-05-14 10:59:36.732330-0700 0x2906d Default 0x0 3663 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x15bd10c80 - WebProcess::updateFreezerStatus() isFreezable: 0, success 2019-05-14 10:59:36.732431-0700 0x2906d Default 0x0 3663 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x15bd10c80 - WebProcess::markAllLayersVolatile() 2019-05-14 10:59:36.732513-0700 0x2906d Default 0x0 3663 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x15bd10c80 - WebProcess::markAllLayersVolatile() Successfuly marked all layers as volatile 2019-05-14 10:59:36.734947-0700 0x29060 Default 0x0 3662 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x109712f40 - WebProcess::processWillSuspendImminently() 2019-05-14 10:59:36.776027-0700 0x29060 Default 0x0 3662 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] WebProcess 3662 is freezing all layer trees 2019-05-14 10:59:36.776091-0700 0x29060 Default 0x0 3662 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x109800808 - WebPage (PageID=1) - Adding a reason 4 to freeze layer tree; current reasons are 2 2019-05-14 10:59:36.776163-0700 0x29060 Default 0x0 3662 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x109712f40 - WebProcess::destroyRenderingResources() took 0.01ms 2019-05-14 10:59:36.778930-0700 0x29060 Default 0x0 3662 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x109712f40 - WebProcess::updateFreezerStatus() isFreezable: 1, success 2019-05-14 10:59:36.779024-0700 0x29060 Default 0x0 3662 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x109712f40 - WebProcess::markAllLayersVolatile() 2019-05-14 10:59:36.781429-0700 0x29058 Default 0x0 3661 0 com.apple.WebKit.Networking: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x1039e47f8 - NetworkProcess::processWillSuspendImminently() 2019-05-14 10:59:36.794408-0700 0x29035 Default 0x6f0c5 3660 0 MobileSafari: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x116b2ac10 - WKProcessAssertionBackgroundTaskManager - endBackgroundTask 2019-05-14 10:59:36.796161-0700 0x29035 Default 0x0 3660 0 MobileSafari: (WebKit) [com.apple.WebKit:ProcessSuspension] UIProcess is taking a background assertion because the Network process is holding locked files 2019-05-14 10:59:36.797298-0700 0x29058 Default 0x0 3661 0 com.apple.WebKit.Networking: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x1039e47f8 - NetworkProcess::processDidResume() This last 2 lines are bad. The UIProcess is being forcibly suspended and is telling its child process via ProcessWillSuspendImminently IPC. The Network process tries to keep itself alive at that point due to locked files, due to activity it does as a result of NetworkProcess::processWillSuspendImminently() getting called. This should be: 2019-05-14 11:26:24.859087-0700 0x2a612 Error 0x72e96 4056 0 MobileSafari: (WebKit) [com.apple.WebKit:ProcessSuspension] Background task expired while holding WebKit ProcessAssertion (isMainThread? 1). 2019-05-14 11:26:24.861170-0700 0x2a63f Default 0x0 4057 0 com.apple.WebKit.Networking: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x1053807f8 - NetworkProcess::processWillSuspendImminently() 2019-05-14 11:26:24.896799-0700 0x2a659 Default 0x0 4059 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x14de111e0 - WebProcess::processWillSuspendImminently() 2019-05-14 11:26:24.927195-0700 0x2a659 Default 0x0 4059 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] WebProcess 4059 is freezing all layer trees 2019-05-14 11:26:24.927266-0700 0x2a659 Default 0x0 4059 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x14de111e0 - WebProcess::destroyRenderingResources() took 0.01ms 2019-05-14 11:26:24.928392-0700 0x2a659 Default 0x0 4059 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x14de111e0 - WebProcess::updateFreezerStatus() isFreezable: 0, success 2019-05-14 11:26:24.929522-0700 0x2a659 Default 0x0 4059 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x14de111e0 - WebProcess::markAllLayersVolatile() 2019-05-14 11:26:24.930031-0700 0x2a659 Default 0x0 4059 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x14de111e0 - WebProcess::markAllLayersVolatile() Successfuly marked all layers as volatile 2019-05-14 11:26:24.931142-0700 0x2a64c Default 0x0 4058 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x12bd170f0 - WebProcess::processWillSuspendImminently() 2019-05-14 11:26:24.969973-0700 0x2a64c Default 0x0 4058 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] WebProcess 4058 is freezing all layer trees 2019-05-14 11:26:24.970020-0700 0x2a64c Default 0x0 4058 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x12c806008 - WebPage (PageID=1) - Adding a reason 4 to freeze layer tree; current reasons are 2 2019-05-14 11:26:24.970588-0700 0x2a64c Default 0x0 4058 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x12bd170f0 - WebProcess::destroyRenderingResources() took 0.52ms 2019-05-14 11:26:24.972108-0700 0x2a64c Default 0x0 4058 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x12bd170f0 - WebProcess::updateFreezerStatus() isFreezable: 1, success 2019-05-14 11:26:24.972638-0700 0x2a64c Default 0x0 4058 0 com.apple.WebKit.WebContent: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x12bd170f0 - WebProcess::markAllLayersVolatile() 2019-05-14 11:26:24.974009-0700 0x2a612 Default 0x72e96 4056 0 MobileSafari: (WebKit) [com.apple.WebKit:ProcessSuspension] 0x1147a8fa0 - WKProcessAssertionBackgroundTaskManager - endBackgroundTask

Attachments
Patch (2.70 KB, patch) 2019-05-14 11:35 PDT, Chris Dumez	no flags	Details Formatted Diff Diff
View All Add attachment proposed patch, testcase, etc.

Chris Dumez

Comment 1 2019-05-14 11:35:44 PDT

Created attachment 369875 [details] Patch

Geoffrey Garen

Comment 2 2019-05-14 11:46:16 PDT

Comment on attachment 369875 [details] Patch r=me

Chris Dumez

Comment 3 2019-05-14 12:27:16 PDT

This is the database activity that's happening as a result of preparing to suspend: com.apple.WebKit.Networking default 12:25:54.299839-0700 5333 0x10154c7f8 - NetworkProcess::processWillSuspendImminently() com.apple.WebKit.Networking default 12:25:54.311009-0700 5333 1 0x101022338 WebKit::WebSQLiteDatabaseTracker::willBeginFirstTransaction() com.apple.WebKit.Networking default 12:25:54.314454-0700 5333 2 0x10596e760 WebCore::SQLiteDatabase::close() com.apple.WebKit.Networking default 12:25:54.317950-0700 5333 3 0x10596e52c WebCore::SQLiteDatabase::~SQLiteDatabase() com.apple.WebKit.Networking default 12:25:54.321923-0700 5333 4 0x105e11f3c WTF::Detail::CallableWrapper<WebCore::RegistrationDatabase::close(WTF::CompletionHandler<void ()>&&)::$_24, void>::call() So we're closing a registration database.

Chris Dumez

Comment 4 2019-05-14 12:30:00 PDT

(In reply to Chris Dumez from comment #3) > This is the database activity that's happening as a result of preparing to > suspend: > com.apple.WebKit.Networking default 12:25:54.299839-0700 5333 0x10154c7f8 - > NetworkProcess::processWillSuspendImminently() > com.apple.WebKit.Networking default 12:25:54.311009-0700 5333 1 > 0x101022338 WebKit::WebSQLiteDatabaseTracker::willBeginFirstTransaction() > com.apple.WebKit.Networking default 12:25:54.314454-0700 5333 2 > 0x10596e760 WebCore::SQLiteDatabase::close() > com.apple.WebKit.Networking default 12:25:54.317950-0700 5333 3 > 0x10596e52c WebCore::SQLiteDatabase::~SQLiteDatabase() > com.apple.WebKit.Networking default 12:25:54.321923-0700 5333 4 > 0x105e11f3c > WTF::Detail::CallableWrapper<WebCore::RegistrationDatabase::close(WTF:: > CompletionHandler<void ()>&&)::$_24, void>::call() > > So we're closing a registration database. Because of this code in actualPrepareToSuspend(): #if ENABLE(SERVICE_WORKER) for (auto& server : m_swServers.values()) server->startSuspension([delayedTaskCounter] { }); #endif which ends up calling: void RegistrationStore::startSuspension(WTF::CompletionHandler<void()>&& completionHandler) { m_isSuspended = true; m_database->close(WTFMove(completionHandler)); } And closing our service worker registrations database.

Chris Dumez

Comment 5 2019-05-14 12:32:21 PDT

Comment on attachment 369875 [details] Patch Clearing flags on attachment: 369875 Committed r245297: <https://trac.webkit.org/changeset/245297>

Chris Dumez

Comment 6 2019-05-14 12:32:23 PDT

All reviewed patches have been landed. Closing bug.

Radar WebKit Bug Importer

Comment 7 2019-05-14 12:35:17 PDT

<rdar://problem/50777823>

Note You need to log in before you can comment on or make changes to this bug.

Status RESOLVED

Resolution FIXED

Priority P2

Severity Normal

Classification Unclassified

Version WebKit Nightly Build

Hardware Unspecified

OS Unspecified

Product WebKit

Component WebKit2

Assignee

Chris Dumez

Reported

2019-05-14 11:29 PDT

Modified

2019-05-14 12:35 PDT History

CC List

6 users Show

URL

Keywords InRadar

Depends on

Blocks