197888 2019-05-14 11:29:51 -0700 The network process tries to take a process assertion when NetworkProcess::processWillSuspendImminently() is called 2019-05-14 12:35:17 -0700 1 1 1 Unclassified WebKit WebKit2 WebKit Nightly Build Unspecified Unspecified RESOLVED FIXED InRadar P2 Normal --- 1 cdumez cdumez achristensen beidson commit-queue ggaren sihui_liu webkit-bug-importer oldest_to_newest 1536155 0 cdumez 2019-05-14 11:29:51 -0700 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 1536159 1 369875 cdumez 2019-05-14 11:35:44 -0700 Created attachment 369875 Patch 1536165 2 369875 ggaren 2019-05-14 11:46:16 -0700 Comment on attachment 369875 Patch r=me 1536179 3 cdumez 2019-05-14 12:27:16 -0700 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. 1536181 4 cdumez 2019-05-14 12:30:00 -0700 (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. 1536184 5 369875 cdumez 2019-05-14 12:32:21 -0700 Comment on attachment 369875 Patch Clearing flags on attachment: 369875 Committed r245297: <https://trac.webkit.org/changeset/245297> 1536185 6 cdumez 2019-05-14 12:32:23 -0700 All reviewed patches have been landed. Closing bug. 1536188 7 webkit-bug-importer 2019-05-14 12:35:17 -0700 <rdar://problem/50777823> 369875 2019-05-14 11:35:44 -0700 2019-05-14 12:32:21 -0700 Patch bug-197888-20190514113543.patch text/plain 2763 cdumez U3VidmVyc2lvbiBSZXZpc2lvbjogMjQ1Mjg5CmRpZmYgLS1naXQgYS9Tb3VyY2UvV2ViS2l0L0No YW5nZUxvZyBiL1NvdXJjZS9XZWJLaXQvQ2hhbmdlTG9nCmluZGV4IDY1OTI0ZDA1ZDczNmRjYzhm YTMxMzc5NjhlYzBmOWMyNjQzZTAyZjkuLmM1MGFkZTMxNzRhNDY1YTIxODhjZmJjZDE1Mzc4MDJk ZGJiNjRiYjEgMTAwNjQ0Ci0tLSBhL1NvdXJjZS9XZWJLaXQvQ2hhbmdlTG9nCisrKyBiL1NvdXJj ZS9XZWJLaXQvQ2hhbmdlTG9nCkBAIC0xLDMgKzEsMjAgQEAKKzIwMTktMDUtMTQgIENocmlzIER1 bWV6ICA8Y2R1bWV6QGFwcGxlLmNvbT4KKworICAgICAgICBUaGUgbmV0d29yayBwcm9jZXNzIHRy aWVzIHRvIHRha2UgYSBwcm9jZXNzIGFzc2VydGlvbiB3aGVuIE5ldHdvcmtQcm9jZXNzOjpwcm9j ZXNzV2lsbFN1c3BlbmRJbW1pbmVudGx5KCkgaXMgY2FsbGVkCisgICAgICAgIGh0dHBzOi8vYnVn cy53ZWJraXQub3JnL3Nob3dfYnVnLmNnaT9pZD0xOTc4ODgKKworICAgICAgICBSZXZpZXdlZCBi eSBOT0JPRFkgKE9PUFMhKS4KKworICAgICAgICBXaGVuIGFjdHVhbFByZXBhcmVUb1N1c3BlbmQo KSBpbiB0aGUgTmV0d29yayBwcm9jZXNzIGlzIGNhbGxlZCBzZXQgdGhlICdJc1N1c3BlbmRlZCcg ZmxhZyBvbiB0aGUgU1FMaXRlIGRhdGFiYXNlIHRyYWNrZXIgYW5kIHVuc2V0CisgICAgICAgIHRo ZSBmbGFnIHdoZW4gdGhlIHByb2Nlc3MgcmVzdW1lLiBUaGlzIGlzIGNvbnNpc3RlbnQgd2l0aCB3 aGF0IHdlIGFscmVhZHkgZG8gaW4gdGhlIFdlYlByb2Nlc3MgYW5kIG1ha2VzIHN1cmUgdGhhdAor ICAgICAgICB0aGUgbmV0d29yayBwcm9jZXNzIGRvZXMgbm90IHRyeSBhbmQgdGFrZSBvbiBhIG5l dyBhc3NlcnRpb24gZHVlIHRvIGxvY2tlZCBmaWxlcyB3aGVuIGdldHRpbmcgbm90aWZpZWQgaXQg aXMgYWJvdXQgdG8gZ2V0CisgICAgICAgIHN1c3BlbmRlZC4KKworICAgICAgICAqIE5ldHdvcmtQ cm9jZXNzL05ldHdvcmtQcm9jZXNzLmNwcDoKKyAgICAgICAgKFdlYktpdDo6TmV0d29ya1Byb2Nl c3M6OmFjdHVhbFByZXBhcmVUb1N1c3BlbmQpOgorICAgICAgICAoV2ViS2l0OjpOZXR3b3JrUHJv Y2Vzczo6cHJvY2Vzc1dpbGxTdXNwZW5kSW1taW5lbnRseSk6CisgICAgICAgIChXZWJLaXQ6Ok5l dHdvcmtQcm9jZXNzOjpyZXN1bWUpOgorCiAyMDE5LTA1LTE0ICBEYW5pZWwgQmF0ZXMgIDxkYWJh dGVzQGFwcGxlLmNvbT4KIAogICAgICAgICBbaU9TXSBDYW5ub3Qgc2Nyb2xsIHRvIGJlZ2lubmlu ZyBvZiBkb2N1bWVudCBhZnRlciBzY3JvbGxpbmcgdG8gZW5kIG9mIGRvY3VtZW50IGFuZCB2aWNl IHZlcnNhIHZpYSBrZXkgY29tbWFuZHMKZGlmZiAtLWdpdCBhL1NvdXJjZS9XZWJLaXQvTmV0d29y a1Byb2Nlc3MvTmV0d29ya1Byb2Nlc3MuY3BwIGIvU291cmNlL1dlYktpdC9OZXR3b3JrUHJvY2Vz cy9OZXR3b3JrUHJvY2Vzcy5jcHAKaW5kZXggYzQ1OWU2M2VkNTc1MTAzOTMzMGNjOWVlYWZjNDlj OGRlMzQ0NWJhZS4uOWM2NDg0NDQ5YzZiYTI3NTAzYzhiYzA1YzcwNzA5YjNlNDNmODk0MyAxMDA2 NDQKLS0tIGEvU291cmNlL1dlYktpdC9OZXR3b3JrUHJvY2Vzcy9OZXR3b3JrUHJvY2Vzcy5jcHAK KysrIGIvU291cmNlL1dlYktpdC9OZXR3b3JrUHJvY2Vzcy9OZXR3b3JrUHJvY2Vzcy5jcHAKQEAg LTE5MjIsNiArMTkyMiwxMCBAQCBwcml2YXRlOgogCiB2b2lkIE5ldHdvcmtQcm9jZXNzOjphY3R1 YWxQcmVwYXJlVG9TdXNwZW5kKFNob3VsZEFja25vd2xlZGdlV2hlblJlYWR5VG9TdXNwZW5kIHNo b3VsZEFja25vd2xlZGdlV2hlblJlYWR5VG9TdXNwZW5kKQogeworI2lmIFBMQVRGT1JNKElPU19G QU1JTFkpCisgICAgbV93ZWJTUUxpdGVEYXRhYmFzZVRyYWNrZXIuc2V0SXNTdXNwZW5kZWQodHJ1 ZSk7CisjZW5kaWYKKwogICAgIGxvd01lbW9yeUhhbmRsZXIoQ3JpdGljYWw6Olllcyk7CiAKICAg ICBSZWZQdHI8VGFza0NvdW50ZXI+IGRlbGF5ZWRUYXNrQ291bnRlcjsKQEAgLTE5NDcsNiArMTk1 MSw3IEBAIHZvaWQgTmV0d29ya1Byb2Nlc3M6OmFjdHVhbFByZXBhcmVUb1N1c3BlbmQoU2hvdWxk QWNrbm93bGVkZ2VXaGVuUmVhZHlUb1N1c3BlbmQKIAogdm9pZCBOZXR3b3JrUHJvY2Vzczo6cHJv Y2Vzc1dpbGxTdXNwZW5kSW1taW5lbnRseShDb21wbGV0aW9uSGFuZGxlcjx2b2lkKGJvb2wpPiYm IGNvbXBsZXRpb25IYW5kbGVyKQogeworICAgIFJFTEVBU0VfTE9HKFByb2Nlc3NTdXNwZW5zaW9u LCAiJXAgLSBOZXR3b3JrUHJvY2Vzczo6cHJvY2Vzc1dpbGxTdXNwZW5kSW1taW5lbnRseSgpIiwg dGhpcyk7CiAjaWYgUExBVEZPUk0oSU9TX0ZBTUlMWSkgJiYgRU5BQkxFKElOREVYRURfREFUQUJB U0UpCiAgICAgZm9yIChhdXRvJiBzZXJ2ZXIgOiBtX2lkYlNlcnZlcnMudmFsdWVzKCkpCiAgICAg ICAgIHNlcnZlci0+dHJ5U3RvcChJREJTZXJ2ZXI6OlNob3VsZEZvcmNlU3RvcDo6WWVzKTsKQEAg LTE5OTQsNiArMTk5OSwxMCBAQCB2b2lkIE5ldHdvcmtQcm9jZXNzOjpwcm9jZXNzRGlkUmVzdW1l KCkKIAogdm9pZCBOZXR3b3JrUHJvY2Vzczo6cmVzdW1lKCkKIHsKKyNpZiBQTEFURk9STShJT1Nf RkFNSUxZKQorICAgIG1fd2ViU1FMaXRlRGF0YWJhc2VUcmFja2VyLnNldElzU3VzcGVuZGVkKGZh bHNlKTsKKyNlbmRpZgorCiAgICAgcGxhdGZvcm1Qcm9jZXNzRGlkUmVzdW1lKCk7CiAgICAgZm9y IChhdXRvJiBjb25uZWN0aW9uIDogbV93ZWJQcm9jZXNzQ29ubmVjdGlvbnMpCiAgICAgICAgIGNv bm5lY3Rpb24tPmVuZFN1c3BlbnNpb24oKTsK