1500619 - PageIconProtocolHandler janks the browser sometimes, especially immediately after switching window focus back to Firefox

Status: NEW

(Firefox :: Menus, defect, P3)

Description

[Mike Conley (:mconley) (:⚙️)]

I've noticed this a few times recently. I'm not sure how long this has been the case, but I finally caught the behaviour in a profile:

https://perfht.ml/2S2OxQA

It looks like on macOS, we can respond to some kind of OS event that causes us to... recompute a bunch of favicons in our menus? Presumably, this is for my bookmarks menu which has a bunch of favicons in it - 1 per entry.

I'm not 100% sure on the STR here, but I'm pretty sure it involves me opening a link from another application when Firefox is in the background. The tab opens, but we drop a ton of frames when animating it open.

We should figure out what's going on here.

Comment 1

[Mike Conley (:mconley) (:⚙️)]

Hey spohl, here's a stack that appears to be kicking off a bunch of page icon requests (for favicons in the bookmarks menu, I believe):

nsMenuItemIconX::SetupIcon()
nsMenuX::MenuConstruct()
nsMenuX::MenuOpened()
-[NSMenu _sendMenuOpeningNotification:]
-[NSCarbonMenuImpl _carbonOpenEvent:handlerCallRef:]
NSSLMMenuEventHandler
DispatchEventToHandlers(EventTargetRec*, OpaqueEventRef*, HandlerCallRec*)
SendEventToEventTargetInternal(OpaqueEventRef*, OpaqueEventTargetRef*, HandlerCallRec*)
SendEventToEventTargetWithOptions
SendMenuOpening(MenuSelectData*, MenuData*, double, unsigned int, unsigned int, __CFDictionary*, unsigned char, unsigned char*)
_SimulateMenuOpening
OpenMenuForInspection(MenuData*)
MenuData::HandleGetNamedAccessibleAttribute(unsigned long long, __CFString const*, unsigned int, OpaqueEventRef*)
MenuData::GetNamedAccessibleAttributeSelf(unsigned long long, __CFString const*, unsigned int, OpaqueEventRef*)
HIObject::DispatchAccessibilityEvent(OpaqueEventRef*, unsigned long long, AccessibilityHandlers const*, void*)
HIObject::HandleClassAccessibilityEvent(OpaqueEventHandlerCallRef*, OpaqueEventRef*, void*)
HIObject::EventHook(OpaqueEventHandlerCallRef*, OpaqueEventRef*, void*)
DispatchEventToHandlers(EventTargetRec*, OpaqueEventRef*, HandlerCallRec*)
SendEventToEventTargetInternal(OpaqueEventRef*, OpaqueEventTargetRef*, HandlerCallRec*)
CallNextEventHandler
-[NSCarbonMenuImpl _carbonGetAccessibleAttributeEvent:handlerCallRef:axElement:]
NSSLMMenuEventHandler
DispatchEventToHandlers(EventTargetRec*, OpaqueEventRef*, HandlerCallRec*)
SendEventToEventTargetInternal(OpaqueEventRef*, OpaqueEventTargetRef*, HandlerCallRec*)
SendEventToEventTargetWithOptions
Accessible::GetNamedAttributeData(__CFString const*, void const*, void const**, unsigned char*)
HLTBCopyUIElementAttributeValue
CarbonCopyAttributeValueCallback(__CFData const*, unsigned int, __CFString const*, void const**, void*)
CopyCarbonUIElementAttributeValue
CopyAttributeValue
_AXXMIGCopyAttributeValue
_XCopyAttributeValue
mshMIGPerform
__CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE1_PERFORM_FUNCTION__
__CFRunLoopDoSource1
__CFRunLoopRun
CFRunLoopRunSpecific
RunCurrentEventLoopInMode
ReceiveNextEventCommon
_BlockUntilNextEventMatchingListInModeWithFilter
_DPSNextEvent
-[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:]
-[GeckoNSApplication nextEventMatchingMask:untilDate:inMode:dequeue:]
-[GeckoNSApplication nextEventMatchingMask:untilDate:inMode:dequeue:]
-[NSApplication run]
nsAppShell::Run()
nsAppStartup::Run()
XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&)
XREMain::XRE_main
mozilla::BootstrapImpl::XRE_main(int, char**, mozilla::BootstrapConfig const&)
main
start
(root)


I'm not actually opening the bookmarks menu though... do you know why we'd be pretending to open the menu here, as I think this stack suggests that we're doing?

Comment 2

[Mike Conley (:mconley) (:⚙️)]

Here's another profile: https://perfht.ml/2yTXClL

Early on in that region, I see this stack as well:

nsMenuBarX::Paint()
+[WindowDelegate paintMenubarForWindow:]
-[WindowDelegate windowDidBecomeMain:]
__CFNOTIFICATIONCENTER_IS_CALLING_OUT_TO_AN_OBSERVER__
_CFXRegistrationPost
___CFXNotificationPost_block_invoke
-[_CFXNotificationRegistrar find:object:observer:enumerator:]
_CFXNotificationPost
-[NSNotificationCenter postNotificationName:object:userInfo:]
_NXShowKeyAndMain
-[NSWindow(NSEventRouting) _handleMouseDownEvent:isDelayedEvent:]
-[NSWindow(NSEventRouting) _reallySendEvent:isDelayedEvent:]
-[NSWindow(NSEventRouting) sendEvent:]
-[ToolbarWindow sendEvent:]
-[NSApplication(NSEvent) sendEvent:]
-[GeckoNSApplication sendEvent:]
-[GeckoNSApplication sendEvent:]
-[NSApplication run]
nsAppShell::Run()
nsAppStartup::Run()
XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&)
XREMain::XRE_main
mozilla::BootstrapImpl::XRE_main(int, char**, mozilla::BootstrapConfig const&)
main
start
(root)

Perhaps this sort of thing is triggered when switching focus from another application back to Firefox?

Comment 3

[Stephen A Pohl [:spohl] (OOO until 3/25)]

This does seem to be related to Firefox gaining focus and given the `History` and `Bookmarks` menus in the menu bar, it seems plausible that we would be requesting favicons for individual entries in those menus.

Comment 4

[Mike Conley (:mconley) (:⚙️)]

I find it kinda strange that we'd be re-querying periodically for this stuff - like, I've seen this profile signature multiple times in the same session.

And since in most cases, I'm _not_ opening up the Bookmarks or History menu, this seems like a waste of work.

Hey Mossop, I know I shouldn't be thinking of you as the favicon guy, but you were last hacking around in this area - do you have any sense why we might be fetching a large batch of page icons in this scenario?

Comment 5

[Marco Bonardo [:mak]]

if the native menubar grabs the bookmarks menu when the app is focused (regardless of the menu being visible), it's maybe expected to also fetch icons. Comment 3 seems to point towards that. Is the same bug visible on Windows?

Comment 6

[Mike Conley (:mconley) (:⚙️)]

(In reply to Marco Bonardo [::mak] from comment #5)
> Is the same bug visible on Windows?

Nope, I'm only seeing this on macOS.

Comment 7

[Stephen A Pohl [:spohl] (OOO until 3/25)]

I'm not sure why the behavior on Windows would be relevant here. macOS has one menu bar at the top of the screen that has to change when different apps receive focus while Windows has the menus contained at the top of each individual application window.

Comment 8

[Marco Bonardo [:mak]]

That's exactly what I was pointing out, this is result of the native menubar, the question is why it needs to fetch all the icons for a menu when the app is focused, rather than when the menu is opened.

Comment 9

[Stephen A Pohl [:spohl] (OOO until 3/25)]

(In reply to Marco Bonardo [::mak] from comment #8)
> That's exactly what I was pointing out, this is result of the native
> menubar, the question is why it needs to fetch all the icons for a menu when
> the app is focused, rather than when the menu is opened.

Ah, I see. If I had to make a guess, the OS might be populating the menu with all the entries (and icons) in order to be ready before the menu is actually opened.

Comment 10

[Marco Bonardo [:mak]]

One thing I was discussing a few days ago with Lina (regarding the new bookmarking system they are working on) was whether we could completely get rid of the bookmarks menu, and rather point users to the sidebar, though that would need to accomodate more accessibility requirements, since the menu is still a primary accessibility point.
Apart from the advantage of having a single bookmarks root (that's what we were discussing: no more menu/toolbar/unfiled/mobile, just a single root and the toolbar becomes a user-definable view) it would also have various perf advantages, among which this one and the fact large menus lag a lot on opening.
That's not a solution to this bug, but it's an orthogonal discussion that I think was worth pointing out.

Comment 11

[Stephen A Pohl [:spohl] (OOO until 3/25)]

This would still leave the `History` menu. But granted, this would presumably be a fraction of the cost of computing every icon in the `Bookmarks` and `History` menu combined, especially for users with lots of bookmarks.

Comment 12

[Dave Townsend [:mossop]]

Sounds like you've got this figured out.

Comment 13

[Marco Bonardo [:mak]]

The History menu is small anyway, it is limited to 15 entries, the bookmarks menu may have hundreds or thousands.
That said, we still need to evaluate a possible short-term approach, unless we want to spend time making an accessible bookmarks sidebar (that maybe could be part of the xul trees rewrite path)...

Comment 14

[:Gijs (he/him)]

https://lists.apple.com/archives/cocoa-dev///2010/Mar/msg01122.html suggests this might be to do with other software and/or a11y options on the machine inspecting menus? Would be good to check if this really affects all macOS installs. :mconley, any chance you could confirm if you've got any external software and/or a11y stuff enabled that might be tripping this?

Otherwise, I can't see why the favicon should matter for these kinds of inspections - would it be possible to detect that's what's triggering the icon check and have the macOS widget menu implementation send a dummy value instead of firing off actual favicon queries? :spohl, is that possible?

Comment 15

[Stephen A Pohl [:spohl] (OOO until 3/25)]

(In reply to :Gijs (he/him) from comment #14)
> Otherwise, I can't see why the favicon should matter for these kinds of
> inspections - would it be possible to detect that's what's triggering the
> icon check and have the macOS widget menu implementation send a dummy value
> instead of firing off actual favicon queries? :spohl, is that possible?

This might lead to not showing favicons in the menu if we don't get called again when the menu actually opens. Would need to verify.

Comment 16

[Mike Conley (:mconley) (:⚙️)]

Attachment: Screen Shot 2018-10-24 at 4.14.44 PM.png

(In reply to :Gijs (he/him) from comment #14)
> https://lists.apple.com/archives/cocoa-dev///2010/Mar/msg01122.html suggests
> this might be to do with other software and/or a11y options on the machine
> inspecting menus? Would be good to check if this really affects all macOS
> installs. :mconley, any chance you could confirm if you've got any external
> software and/or a11y stuff enabled that might be tripping this?
> 

I'm not sure what accessibility software or options these might be...

Here's a screenshot of the accessibility menu item in the menubar - it looks like everything is off. Can I trust that?

Alternatively, spohl, do you know if there's any way for me to hard-disable all accessibility features in macOS to test this hypothesis?

Comment 17

[Stephen A Pohl [:spohl] (OOO until 3/25)]

(In reply to Mike Conley (:mconley) (:⚙️) from comment #16)
> Alternatively, spohl, do you know if there's any way for me to hard-disable
> all accessibility features in macOS to test this hypothesis?

I wouldn't know of a way besides unchecking everything in Accessibility under System Preferences.

Comment 18

[Mike Conley (:mconley) (:⚙️)]

Hm. I can still get the _XCopyAttributeValue stuff to show up when switching window focus even with everything unchecked from the System Preferences Accessibility pane:

https://perfht.ml/2SgKFeD

Hey yzen, do you know if it's expected that I hit this stack when switching window focus on macOS, even when I'm not using any accessibility APIs (that I'm aware of):


nsMenuX::MenuOpened()
-[NSMenu _sendMenuOpeningNotification:]
-[NSCarbonMenuImpl _carbonOpenEvent:handlerCallRef:]
NSSLMMenuEventHandler
DispatchEventToHandlers(EventTargetRec*, OpaqueEventRef*, HandlerCallRec*)
SendEventToEventTargetInternal(OpaqueEventRef*, OpaqueEventTargetRef*, HandlerCallRec*)
SendEventToEventTargetWithOptions
SendMenuOpening(MenuSelectData*, MenuData*, double, unsigned int, unsigned int, __CFDictionary*, unsigned char, unsigned char*)
_SimulateMenuOpening
OpenMenuForInspection(MenuData*)
MenuData::HandleGetNamedAccessibleAttribute(unsigned long long, __CFString const*, unsigned int, OpaqueEventRef*)
MenuData::GetNamedAccessibleAttributeSelf(unsigned long long, __CFString const*, unsigned int, OpaqueEventRef*)
HIObject::DispatchAccessibilityEvent(OpaqueEventRef*, unsigned long long, AccessibilityHandlers const*, void*)
HIObject::HandleClassAccessibilityEvent(OpaqueEventHandlerCallRef*, OpaqueEventRef*, void*)
HIObject::EventHook(OpaqueEventHandlerCallRef*, OpaqueEventRef*, void*)
DispatchEventToHandlers(EventTargetRec*, OpaqueEventRef*, HandlerCallRec*)
SendEventToEventTargetInternal(OpaqueEventRef*, OpaqueEventTargetRef*, HandlerCallRec*)
CallNextEventHandler
-[NSCarbonMenuImpl _carbonGetAccessibleAttributeEvent:handlerCallRef:axElement:]
NSSLMMenuEventHandler
DispatchEventToHandlers(EventTargetRec*, OpaqueEventRef*, HandlerCallRec*)
SendEventToEventTargetInternal(OpaqueEventRef*, OpaqueEventTargetRef*, HandlerCallRec*)
SendEventToEventTargetWithOptions
Accessible::GetNamedAttributeData(__CFString const*, void const*, void const**, unsigned char*)
HLTBCopyUIElementAttributeValue
CarbonCopyAttributeValueCallback(__CFData const*, unsigned int, __CFString const*, void const**, void*)
CopyCarbonUIElementAttributeValue
CopyAttributeValue
_AXXMIGCopyAttributeValue
_XCopyAttributeValue
mshMIGPerform
__CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE1_PERFORM_FUNCTION__
__CFRunLoopDoSource1
__CFRunLoopRun
CFRunLoopRunSpecific
RunCurrentEventLoopInMode
ReceiveNextEventCommon
_BlockUntilNextEventMatchingListInModeWithFilter
_DPSNextEvent
-[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:]
-[GeckoNSApplication nextEventMatchingMask:untilDate:inMode:dequeue:]
-[GeckoNSApplication nextEventMatchingMask:untilDate:inMode:dequeue:]
-[NSApplication run]
nsAppShell::Run()
nsAppStartup::Run()
XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&)
XREMain::XRE_main
mozilla::BootstrapImpl::XRE_main(int, char**, mozilla::BootstrapConfig const&)
main
start
(root)

Comment 19

[Mike Conley (:mconley) (:⚙️)]

(I'll also note that I have "Prevent accessibility services from accessing your browser" checked in about:preferences...)

Comment 20

[Yura Zenevich [:yzen] (please use "needinfo")]

As per out chat with @mconley in person, doesn't seem like anything accessibility related is instantiated.

Comment 21

[Florian Quèze [:florian]]

Mike, I had the same issue on my previous macbook 2 mainboards ago. It's actually the reason why I decided to re-install a fresh system instead of restoring from my Time Machine backup when I had the mainboard replaced.

Something somewhere is causing accessibility events that cause a _SimulateMenuOpening call. This was very annoying for me because it makes the browser_startup.js test fail (as opening the menus early causes Places to be initialized earlier than usual). The problem goes away when rebooting, and I later realized that I didn't need to reboot, killing the universalaccessd process is enough for the problem to go away for a few minutes or hours.

I've never managed to figure out the actual cause.