[iOS 14] Hang in -[WKUserDefaults _notifyObserversOfChangeFromValuesForKeys:toValuesForKeys:]

[Ali Juma]

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

[Radar WebKit Bug Importer]

<rdar://problem/69916673>

[Brent Fulgham]

(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?

[Ali Juma]

(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.

[Per Arne Vollan]

(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?

[Ali Juma]

(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").

[Per Arne Vollan]

(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?

[Ali Juma]

(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.

[Per Arne Vollan]

Created attachment 411151 [details]
Patch

[Per Arne Vollan]

Created attachment 411165 [details]
Patch

[Per Arne Vollan]

Created attachment 411167 [details]
Patch

[Geoffrey Garen]

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.

[Per Arne Vollan]

(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!

[Geoffrey Garen]

Comment on attachment 411167 [details]
Patch

I guess there's no harm in doing this on a secondary thread 🤷🏻‍♂️

[Per Arne Vollan]

Comment on attachment 411167 [details]
Patch

Thanks for reviewing!

[EWS]

Committed r268421: <https://trac.webkit.org/changeset/268421>

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

[Darin Adler]

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?

[Per Arne Vollan]

(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!

[Darin Adler]

(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?

[Per Arne Vollan]

Created attachment 411318 [details]
Patch

[Per Arne Vollan]

(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.