Bug 217183

Summary: [iOS 14] Hang in -[WKUserDefaults _notifyObserversOfChangeFromValuesForKeys:toValuesForKeys:]
Product: WebKit Reporter: Ali Juma <ajuma>
Component: WebKit APIAssignee: Nobody <webkit-unassigned>
Status: RESOLVED FIXED    
Severity: Normal CC: bfulgham, darin, ggaren, pvollan, webkit-bug-importer
Priority: P2 Keywords: InRadar
Version: WebKit Nightly Build   
Hardware: Unspecified   
OS: Unspecified   
See Also: https://bugs.webkit.org/show_bug.cgi?id=203420
Attachments:
Description Flags
Patch
none
Patch
none
Patch
none
Patch pvollan: commit-queue+

Description Ali Juma 2020-10-01 10:59:00 PDT
Chrome for iOS is getting a significant number of hang reports in -[WKUserDefaults _notifyObserversOfChangeFromValuesForKeys:toValuesForKeys:] on iOS 14.

This code was added in bug 203420.

We don't have steps to reproduce, but the reports suggest that this happens after the app is backgrounded.

Here's the stack:
(libobjc.A.dylib)       class_conformsToProtocol
(libobjc.A.dylib)       +[NSObject conformsToProtocol:]
(Foundation)            -[NSCoder validateClassSupportsSecureCoding:]
(Foundation)            _encodeObject
(Foundation)            +[NSKeyedArchiver archivedDataWithRootObject:requiringSecureCoding:error:]
(WebKit)                -[WKUserDefaults _notifyObserversOfChangeFromValuesForKeys:toValuesForKeys:]
(CoreFoundation)        -[CFPrefsSource forEachObserver:]
(CoreFoundation)        -[CFPrefsSource _notifyObserversOfChangeFromValuesForKeys:toValuesForKeys:]
(CoreFoundation)        ___CFPrefsDeliverPendingKVONotificationsGuts_block_invoke
(CoreFoundation)        __CFDictionaryApplyFunction_block_invoke
(CoreFoundation)        CFBasicHashApply
(CoreFoundation)        CFDictionaryApplyFunction
(CoreFoundation)        _CFPrefsDeliverPendingKVONotificationsGuts
(CoreFoundation)        __CFRUNLOOP_IS_CALLING_OUT_TO_A_BLOCK__
(CoreFoundation)        __CFRunLoopDoBlocks
(CoreFoundation)        __CFRunLoopRun
(CoreFoundation)        CFRunLoopRunSpecific
(GraphicsServices)      GSEventRunModal
(UIKitCore)             -[UIApplication _run]
(UIKitCore)             UIApplicationMain
Comment 1 Radar WebKit Bug Importer 2020-10-03 09:46:23 PDT
<rdar://problem/69916673>
Comment 2 Brent Fulgham 2020-10-06 14:04:51 PDT
(In reply to Ali Juma from comment #0)
> Chrome for iOS is getting a significant number of hang reports in
> -[WKUserDefaults _notifyObserversOfChangeFromValuesForKeys:toValuesForKeys:]
> on iOS 14.

Do you have any visibility into what preference is being accessed?
Comment 3 Ali Juma 2020-10-07 06:37:12 PDT
(In reply to Brent Fulgham from comment #2)
> (In reply to Ali Juma from comment #0)
> > Chrome for iOS is getting a significant number of hang reports in
> > -[WKUserDefaults _notifyObserversOfChangeFromValuesForKeys:toValuesForKeys:]
> > on iOS 14.
> 
> Do you have any visibility into what preference is being accessed?

No, the crash reports we have don't contain that.
Comment 4 Per Arne Vollan 2020-10-07 12:27:28 PDT
(In reply to Ali Juma from comment #3)
> (In reply to Brent Fulgham from comment #2)
> > (In reply to Ali Juma from comment #0)
> > > Chrome for iOS is getting a significant number of hang reports in
> > > -[WKUserDefaults _notifyObserversOfChangeFromValuesForKeys:toValuesForKeys:]
> > > on iOS 14.
> > 
> > Do you have any visibility into what preference is being accessed?
> 
> No, the crash reports we have don't contain that.

Is this a hang or a crash? (In reply to Ali Juma from comment #3)
> (In reply to Brent Fulgham from comment #2)
> > (In reply to Ali Juma from comment #0)
> > > Chrome for iOS is getting a significant number of hang reports in
> > > -[WKUserDefaults _notifyObserversOfChangeFromValuesForKeys:toValuesForKeys:]
> > > on iOS 14.
> > 
> > Do you have any visibility into what preference is being accessed?
> 
> No, the crash reports we have don't contain that.

Ali, is this a crash or a hang?
Comment 5 Ali Juma 2020-10-07 13:28:53 PDT
(In reply to Per Arne Vollan from comment #4)
> > (In reply to Brent Fulgham from comment #2)
> > > (In reply to Ali Juma from comment #0)
> > > > Chrome for iOS is getting a significant number of hang reports in
> > > > -[WKUserDefaults _notifyObserversOfChangeFromValuesForKeys:toValuesForKeys:]
> > > > on iOS 14.
> > > 
> > > Do you have any visibility into what preference is being accessed?
> > 
> > No, the crash reports we have don't contain that.
> 
> Ali, is this a crash or a hang?

It's a hang (meant to say "hang reports" rather than "crash reports").
Comment 6 Per Arne Vollan 2020-10-08 08:50:01 PDT
(In reply to Ali Juma from comment #5)
> (In reply to Per Arne Vollan from comment #4)
> > > (In reply to Brent Fulgham from comment #2)
> > > > (In reply to Ali Juma from comment #0)
> > > > > Chrome for iOS is getting a significant number of hang reports in
> > > > > -[WKUserDefaults _notifyObserversOfChangeFromValuesForKeys:toValuesForKeys:]
> > > > > on iOS 14.
> > > > 
> > > > Do you have any visibility into what preference is being accessed?
> > > 
> > > No, the crash reports we have don't contain that.
> > 
> > Ali, is this a crash or a hang?
> 
> It's a hang (meant to say "hang reports" rather than "crash reports").

Thanks! Do you have information about the hang time, for example average, max, and min?
Comment 7 Ali Juma 2020-10-08 10:46:01 PDT
(In reply to Per Arne Vollan from comment #6)
> (In reply to Ali Juma from comment #5)
> > (In reply to Per Arne Vollan from comment #4)
> > > > (In reply to Brent Fulgham from comment #2)
> > > > > (In reply to Ali Juma from comment #0)
> > > > > > Chrome for iOS is getting a significant number of hang reports in
> > > > > > -[WKUserDefaults _notifyObserversOfChangeFromValuesForKeys:toValuesForKeys:]
> > > > > > on iOS 14.
> > > > > 
> > > > > Do you have any visibility into what preference is being accessed?
> > > > 
> > > > No, the crash reports we have don't contain that.
> > > 
> > > Ali, is this a crash or a hang?
> > 
> > It's a hang (meant to say "hang reports" rather than "crash reports").
> 
> Thanks! Do you have information about the hang time, for example average,
> max, and min?

It's at least 9 seconds (that's the minimum before we get a report), but we don't have the average or the max.
Comment 8 Per Arne Vollan 2020-10-12 13:42:56 PDT
Created attachment 411151 [details]
Patch
Comment 9 Per Arne Vollan 2020-10-12 15:00:23 PDT
Created attachment 411165 [details]
Patch
Comment 10 Per Arne Vollan 2020-10-12 15:01:40 PDT
Created attachment 411167 [details]
Patch
Comment 11 Geoffrey Garen 2020-10-13 09:40:35 PDT
Given that the we don't know the upper limit of the hang, how do we know that dispatching to a secondary thread will resolve it?

Especially strange to hang in class_conformsToProtocol. That implies some kind of memory corruption in an Obj-C object or in the Obj-C runtime.
Comment 12 Per Arne Vollan 2020-10-13 13:12:50 PDT
(In reply to Geoffrey Garen from comment #11)
> Given that the we don't know the upper limit of the hang, how do we know
> that dispatching to a secondary thread will resolve it?
> 
> Especially strange to hang in class_conformsToProtocol. That implies some
> kind of memory corruption in an Obj-C object or in the Obj-C runtime.

Yes, you are right. This patch only makes sure that we do not block Chrome’s main thread, making it unresponsive. The patch does not address why we seem to be stuck in conformsToProtocol for a substantial amount of time. At this point, the reason for this is unknown, and I have not been able to reproduce so far.

Thanks for reviewing!
Comment 13 Geoffrey Garen 2020-10-13 14:23:26 PDT
Comment on attachment 411167 [details]
Patch

I guess there's no harm in doing this on a secondary thread 🤷🏻‍♂️
Comment 14 Per Arne Vollan 2020-10-13 14:31:47 PDT
Comment on attachment 411167 [details]
Patch

Thanks for reviewing!
Comment 15 EWS 2020-10-13 14:38:26 PDT
Committed r268421: <https://trac.webkit.org/changeset/268421>

All reviewed patches have been landed. Closing bug and clearing flags on attachment 411167 [details].
Comment 16 Darin Adler 2020-10-13 14:53:26 PDT
Comment on attachment 411167 [details]
Patch

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

> Source/WebKit/UIProcess/Cocoa/PreferenceObserver.mm:95
> +    if (!isMainThread()) {
> +        [self findPreferenceChangesAndNotifyForKeys:oldValues toValuesForKeys:newValues];
> +        return;
> +    }

Why do we need this?
Comment 17 Per Arne Vollan 2020-10-13 15:37:06 PDT
(In reply to Darin Adler from comment #16)
> Comment on attachment 411167 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=411167&action=review
> 
> > Source/WebKit/UIProcess/Cocoa/PreferenceObserver.mm:95
> > +    if (!isMainThread()) {
> > +        [self findPreferenceChangesAndNotifyForKeys:oldValues toValuesForKeys:newValues];
> > +        return;
> > +    }
> 
> Why do we need this?

This is to avoid extra thread hopping if the method is already being called on a non-main thread.

Thanks for reviewing!
Comment 18 Darin Adler 2020-10-13 17:09:03 PDT
(In reply to Per Arne Vollan from comment #17)
> This is to avoid extra thread hopping if the method is already being called
> on a non-main thread.

But *why* is avoiding extra thread hopping a good thing? Is there some reason that non-main threads are always OK to block?
Comment 19 Per Arne Vollan 2020-10-14 06:48:57 PDT
Created attachment 411318 [details]
Patch
Comment 20 Per Arne Vollan 2020-10-14 06:53:17 PDT
(In reply to Darin Adler from comment #18)
> (In reply to Per Arne Vollan from comment #17)
> > This is to avoid extra thread hopping if the method is already being called
> > on a non-main thread.
> 
> But *why* is avoiding extra thread hopping a good thing? Is there some
> reason that non-main threads are always OK to block?

Ah, I see now, that's a good point. For local preference changes, this method will be called on the thread which made the change, and it would be good to avoid blocking that thread as well. I have uploaded a new patch which removes this piece of code.